vm-test-run-nixos-test-k3s
checks.aarch64-linux.nixos-test-k3s
· build #509
· raw
1tribuchet: building on eliza2[0.00s] Machine state will be reset. To keep it, pass --keep-machine-state3[0.00s] start all VLans4[0.00s] (finished: start all VLans, in 0.00 seconds)5[0.00s] Test will time out and terminate in 3600.0 seconds6[0.00s] run the VM test script7[0.01s] machine: waiting for unit k3s.service8[0.01s] machine: waiting for the VM to finish booting9[0.01s] machine: starting vm10[0.39s] machine: QEMU running (pid 45)11machine # Disk image does not exist, creating the virtualisation disk image...12machine # Formatting '/build/vm-state-machine/tmp.HPBRiJVHkv', fmt=raw size=858993459213machine # mke2fs 1.47.4 (6-Mar-2025)14machine # Discarding device blocks: 0/2097152 done15machine # Creating filesystem with 2097152 4k blocks and 524288 inodes16machine # Filesystem UUID: 6fa3e7fb-60a8-4689-8d1e-7366174acbda17machine # Superblock backups stored on blocks:18machine # 32768, 98304, 163840, 229376, 294912, 819200, 884736, 160563219machine # 20machine # Allocating group tables: 0/64 done21machine # Writing inode tables: 0/64 done22machine # Creating journal (16384 blocks): done23machine # Writing superblocks and filesystem accounting information: 0/64 done24machine # 25machine # Virtualisation disk image created.26machine # Starting virtiofs daemons...27machine # [2026-11-12T11:49:45Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)28machine # [2026-11-12T11:49:45Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether29machine # [2026-11-12T11:49:45Z INFO virtiofsd] Waiting for vhost-user socket connection...30machine # [2026-11-12T11:49:45Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)31machine # [2026-11-12T11:49:45Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether32machine # [2026-11-12T11:49:45Z INFO virtiofsd] Waiting for vhost-user socket connection...33machine # [2026-11-12T11:49:45Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)34machine # [2026-11-12T11:49:45Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether35machine # [2026-11-12T11:49:45Z INFO virtiofsd] Waiting for vhost-user socket connection...36machine # [2026-11-12T11:49:45Z INFO virtiofsd] Client connected, servicing requests37machine # [2026-11-12T11:49:45Z INFO virtiofsd] Client connected, servicing requests38machine # [2026-11-12T11:49:45Z INFO virtiofsd] Client connected, servicing requests39machine # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]40machine # [ 0.000000] Linux version 6.18.60 (nixbld@localhost) (gcc (GCC) 16.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT @179336200141machine # [ 0.000000] KASLR enabled42machine # [ 0.000000] random: crng init done43machine # [ 0.000000] Machine model: linux,dummy-virt44machine # [ 0.000000] efi: UEFI not found.45machine # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT46machine # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000ffffffff]47machine # [ 0.000000] NODE_DATA(0) allocated [mem 0xffdec0c0-0xffdef83f]48machine # [ 0.000000] Zone ranges:49machine # [ 0.000000] DMA [mem 0x0000000040000000-0x00000000ffffffff]50machine # [ 0.000000] DMA32 empty51machine # [ 0.000000] Normal empty52machine # [ 0.000000] Device empty53machine # [ 0.000000] Movable zone start for each node54machine # [ 0.000000] Early memory node ranges55machine # [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000ffffffff]56machine # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x00000000ffffffff]57machine # [ 0.000000] cma: Reserved 32 MiB at 0x00000000fac0000058machine # [ 0.000000] psci: probing for conduit method from DT.59machine # [ 0.000000] psci: PSCIv1.3 detected in firmware.60machine # [ 0.000000] psci: Using standard PSCI v0.2 function IDs61machine # [ 0.000000] psci: Trusted OS migration not required62machine # [ 0.000000] psci: SMC Calling Convention v1.163machine # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)64machine # [ 0.000000] percpu: Embedded 76 pages/cpu s187672 r8192 d115432 u31129665machine # [ 0.000000] Detected PIPT I-cache on CPU066machine # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)67machine # [ 0.000000] CPU features: detected: GICv3 CPU interface68machine # [ 0.000000] CPU features: detected: Spectre-v469machine # [ 0.000000] CPU features: detected: Spectre-BHB70machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_3871machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_2372machine # [ 0.000000] alternatives: applying boot alternatives73machine # [ 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/8s3psb7bl59psh19j3h9r70x07wzhccv-nixos-system-machine-test/init regInfo=/nix/.ro-store/y13r0644r9fr3s9n809dyr0mam65xv6c-closure-info/registration console=ttyAMA0,115200n8 console=tty074machine # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/y13r0644r9fr3s9n809dyr0mam65xv6c-closure-info/registration", will be passed to user space.75machine # [ 0.000000] printk: log buffer data + meta data: 1048576 + 3670016 = 4718592 bytes76machine # [ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)77machine # [ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)78machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 3MB79machine # [ 0.000000] software IO TLB: area num 2.80machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size roundup to 4MB81machine # [ 0.000000] software IO TLB: mapped [mem 0x00000000fa200000-0x00000000fa600000] (4MB)82machine # [ 0.000000] Fallback order for Node 0: 083machine # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 78643284machine # [ 0.000000] Policy zone: DMA85machine # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off86machine # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=187machine # [ 0.000000] allocated 6291456 bytes of page_ext88machine # [ 0.000000] ftrace: allocating 75323 entries in 296 pages89machine # [ 0.000000] ftrace: allocated 296 pages with 3 groups90machine # [ 0.000000] rcu: Hierarchical RCU implementation.91machine # [ 0.000000] rcu: RCU event tracing is enabled.92machine # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=2.93machine # [ 0.000000] Trampoline variant of Tasks RCU enabled.94machine # [ 0.000000] Rude variant of Tasks RCU enabled.95machine # [ 0.000000] Tracing variant of Tasks RCU enabled.96machine # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.97machine # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=298machine # [ 0.000000] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.99machine # [ 0.000000] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.100machine # [ 0.000000] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.101machine # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0102machine # [ 0.000000] GICv3: 256 SPIs implemented103machine # [ 0.000000] GICv3: 0 Extended SPIs implemented104machine # [ 0.000000] Root IRQ handler: gic_handle_irq105machine # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI106machine # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0107machine # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000108machine # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]109machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @45510000 (indirect, esz 8, psz 64K, shr 1)110machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @45520000 (flat, esz 8, psz 64K, shr 1)111machine # [ 0.000000] GICv3: using LPI property table @0x0000000045530000112machine # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000045540000113machine # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.114machine # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns115machine # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).116machine # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns117machine # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns118machine # [ 0.000033] arm-pv: using stolen time PV119machine # [ 0.000402] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)120machine # [ 0.000574] Console: colour dummy device 80x25121machine # [ 0.000583] printk: legacy console [tty0] enabled122machine # [ 0.000786] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)123machine # [ 0.000793] pid_max: default: 32768 minimum: 301124machine # [ 0.000866] LSM: initializing lsm=lockdown,capability,landlock,yama,bpf,ima125machine # [ 0.000996] landlock: Up and running.126machine # [ 0.000999] Yama: becoming mindful.127machine # [ 0.001436] LSM support for eBPF active128machine # [ 0.001613] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)129machine # [ 0.001676] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)130machine # [ 0.003676] rcu: Hierarchical SRCU implementation.131machine # [ 0.003680] rcu: Max phase no-delay instances is 1000.132machine # [ 0.003848] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level133machine # [ 0.005096] fsl-mc MSI: its@8080000 domain created134machine # [ 0.005223] EFI services will not be available.135machine # [ 0.005339] smp: Bringing up secondary CPUs ...136machine # [ 0.005902] Detected PIPT I-cache on CPU1137machine # [ 0.005967] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000138machine # [ 0.006042] GICv3: CPU1: using allocated LPI pending table @0x0000000045550000139machine # [ 0.006119] CPU1: Booted secondary processor 0x0000000001 [0xc00fac40]140machine # [ 0.006493] smp: Brought up 1 node, 2 CPUs141machine # [ 0.006509] SMP: Total of 2 processors activated.142machine # [ 0.006511] CPU: All CPU(s) started at EL1143machine # [ 0.006520] CPU features: detected: Branch Target Identification144machine # [ 0.006523] CPU features: detected: ARMv8.4 Translation Table Level145machine # [ 0.006526] CPU features: detected: Instruction cache invalidation not required for I/D coherence146machine # [ 0.006529] CPU features: detected: Data cache clean to the PoU not required for I/D coherence147machine # [ 0.006532] CPU features: detected: Common not Private translations148machine # [ 0.006535] CPU features: detected: CRC32 instructions149machine # [ 0.006537] CPU features: detected: Data cache clean to Point of Deep Persistence150machine # [ 0.006541] CPU features: detected: Data cache clean to Point of Persistence151machine # [ 0.006543] CPU features: detected: Data independent timing control (DIT)152machine # [ 0.006546] CPU features: detected: E0PD153machine # [ 0.006548] CPU features: detected: Enhanced Counter Virtualization154machine # [ 0.006551] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)155machine # [ 0.006554] CPU features: detected: Enhanced Virtualization Traps156machine # [ 0.006557] CPU features: detected: Fine Grained Traps157machine # [ 0.006560] CPU features: detected: Generic authentication (architected QARMA5 algorithm)158machine # [ 0.006563] CPU features: detected: RCpc load-acquire (LDAPR)159machine # [ 0.006569] CPU features: detected: LSE atomic instructions160machine # [ 0.006572] CPU features: detected: Privileged Access Never161machine # [ 0.006574] CPU features: detected: PMUv3162machine # [ 0.006577] CPU features: detected: RAS Extension Support163machine # [ 0.006580] CPU features: detected: RASv1p1 Extension Support164machine # [ 0.006582] CPU features: detected: Random Number Generator165machine # [ 0.006585] CPU features: detected: Speculation barrier (SB)166machine # [ 0.006587] CPU features: detected: Stage-2 Force Write-Back167machine # [ 0.006590] CPU features: detected: TLB range maintenance instructions168machine # [ 0.006594] CPU features: detected: Speculative Store Bypassing Safe (SSBS)169machine # [ 0.006659] alternatives: applying system-wide alternatives170machine # [ 0.009655] CPU features: detected: BBM Level 2 without TLB conflict abort171machine # [ 0.009793] Memory: 2938440K/3145728K available (24640K kernel code, 10246K rwdata, 26664K rodata, 7808K init, 2086K bss, 160580K reserved, 32768K cma-reserved)172machine # [ 0.010811] devtmpfs: initialized173machine # [ 0.013592] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)174machine # [ 0.013630] futex hash table entries: 512 (32768 bytes on 1 NUMA nodes, total 32 KiB, linear).175machine # [ 0.013861] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL176machine # [ 0.013869] 0 pages in range for non-PLT usage177machine # [ 0.013870] 506368 pages in range for PLT usage178machine # [ 0.013992] pinctrl core: initialized pinctrl subsystem179machine # [ 0.014840] DMI not present or invalid.180machine # [ 0.018068] NET: Registered PF_NETLINK/PF_ROUTE protocol family181machine # [ 0.020426] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations182machine # [ 0.020761] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations183machine # [ 0.021079] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations184machine # [ 0.021102] audit: initializing netlink subsys (disabled)185machine # [ 0.021555] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1186machine # [ 0.022899] thermal_sys: Registered thermal governor 'fair_share'187machine # [ 0.022905] thermal_sys: Registered thermal governor 'bang_bang'188machine # [ 0.022913] thermal_sys: Registered thermal governor 'step_wise'189machine # [ 0.022917] thermal_sys: Registered thermal governor 'user_space'190machine # [ 0.022921] thermal_sys: Registered thermal governor 'power_allocator'191machine # [ 0.022986] cpuidle: using governor ladder192machine # [ 0.023014] cpuidle: using governor menu193machine # [ 0.023451] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.194machine # [ 0.023512] ASID allocator initialised with 65536 entries195machine # [ 0.025468] Serial: AMBA PL011 UART driver196machine # [ 0.034583] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1197machine # [ 0.034727] printk: console [ttyAMA0] enabled198machine # [ 0.179554] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages199machine # [ 0.179569] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page200machine # [ 0.179574] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages201machine # [ 0.179578] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page202machine # [ 0.179582] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages203machine # [ 0.179586] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page204machine # [ 0.179591] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages205machine # [ 0.179595] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page206machine # [ 0.196054] fbcon: Taking over console207machine # [ 0.196073] ACPI: Interpreter disabled.208machine # [ 0.199207] iommu: Default domain type: Translated209machine # [ 0.199215] iommu: DMA domain TLB invalidation policy: strict mode210machine # [ 0.199642] SCSI subsystem initialized211machine # [ 0.200043] usbcore: registered new interface driver usbfs212machine # [ 0.200081] usbcore: registered new interface driver hub213machine # [ 0.200100] usbcore: registered new device driver usb214machine # [ 0.200419] pps_core: LinuxPPS API ver. 1 registered215machine # [ 0.200423] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>216machine # [ 0.200432] PTP clock support registered217machine # [ 0.200486] EDAC MC: Ver: 3.0.0218machine # [ 0.200743] scmi_core: SCMI protocol bus registered219machine # [ 0.201466] FPGA manager framework220machine # [ 0.202617] vgaarb: loaded221machine # [ 0.203123] clocksource: Switched to clocksource arch_sys_counter222machine # [ 0.204047] VFS: Disk quotas dquot_6.6.0223machine # [ 0.204101] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)224machine # [ 0.204691] netfs: FS-Cache loaded225machine # [ 0.204902] pnp: PnP ACPI: disabled226machine # [ 0.210190] NET: Registered PF_INET protocol family227machine # [ 0.210980] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)228machine # [ 0.250941] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)229machine # [ 0.250991] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)230machine # [ 0.251032] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)231machine # [ 0.251427] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)232machine # [ 0.251801] TCP: Hash tables configured (established 32768 bind 32768)233machine # [ 0.251908] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear)234machine # [ 0.251960] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)235machine # [ 0.252038] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)236machine # [ 0.252207] NET: Registered PF_UNIX/PF_LOCAL protocol family237machine # [ 0.252228] NET: Registered PF_XDP protocol family238machine # [ 0.252246] PCI: CLS 0 bytes, default 64239machine # [ 0.252549] Trying to unpack rootfs image as initramfs...240machine # [ 0.261504] kvm [1]: HYP mode not available241machine # [ 0.307900] Initialise system trusted keyrings242machine # [ 0.307976] Key type blacklist registered243machine # [ 0.311328] workingset: timestamp_bits=42 max_order=20 bucket_order=0244machine # [ 0.311863] squashfs: version 4.0 (2009/01/31) Phillip Lougher245machine # [ 0.311929] 9p: Installing v9fs 9p2000 file system support246machine # [ 0.312080] integrity: Platform Keyring initialized247machine # [ 0.312092] integrity: Machine keyring initialized248machine # [ 0.324099] Key type asymmetric registered249machine # [ 0.324107] Asymmetric key parser 'x509' registered250machine # [ 0.324154] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)251machine # [ 0.324276] io scheduler mq-deadline registered252machine # [ 0.324282] io scheduler kyber registered253machine # [ 0.335623] pl061_gpio 9030000.pl061: PL061 GPIO chip registered254machine # [ 0.339191] ledtrig-cpu: registered to indicate activity on CPUs255machine # [ 0.339874] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:256machine # [ 0.339894] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000257machine # [ 0.339931] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000258machine # [ 0.339937] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000259machine # [ 0.339956] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits260machine # [ 0.339986] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]261machine # [ 0.340117] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00262machine # [ 0.340127] pci_bus 0000:00: root bus resource [bus 00-ff]263machine # [ 0.340131] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]264machine # [ 0.340134] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]265machine # [ 0.340137] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]266machine # [ 0.340282] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint267machine # [ 0.340870] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint268machine # [ 0.341101] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]269machine # [ 0.341115] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]270machine # [ 0.341147] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]271machine # [ 0.341159] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]272machine # [ 0.341743] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint273machine # [ 0.341981] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]274machine # [ 0.341993] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]275machine # [ 0.342020] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]276machine # [ 0.342583] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint277machine # [ 0.342809] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]278machine # [ 0.342820] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]279machine # [ 0.342847] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]280machine # [ 0.343416] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint281machine # [ 0.343655] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]282machine # [ 0.343667] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]283machine # [ 0.343696] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]284machine # [ 0.343709] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]285machine # [ 0.344283] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint286machine # [ 0.344518] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]287machine # [ 0.344545] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]288machine # [ 0.345132] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint289machine # [ 0.345364] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]290machine # [ 0.345396] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]291machine # [ 0.345870] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint292machine # [ 0.346099] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]293machine # [ 0.346430] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint294machine # [ 0.346677] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]295machine # [ 0.346705] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]296machine # [ 0.355341] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint297machine # [ 0.355575] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]298machine # [ 0.355607] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]299machine # [ 0.356223] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint300machine # [ 0.356467] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]301machine # [ 0.356502] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]302machine # [ 0.357058] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint303machine # [ 0.357388] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]304machine # [ 0.357402] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]305machine # [ 0.357429] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]306machine # [ 0.358000] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint307machine # [ 0.358219] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]308machine # [ 0.358231] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]309machine # [ 0.358262] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]310machine # [ 0.359044] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned311machine # [ 0.359055] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned312machine # [ 0.359059] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned313machine # [ 0.359106] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned314machine # [ 0.359174] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned315machine # [ 0.359231] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned316machine # [ 0.359282] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned317machine # [ 0.359328] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned318machine # [ 0.359374] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned319machine # [ 0.359424] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned320machine # [ 0.359483] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned321machine # [ 0.359528] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned322machine # [ 0.359619] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned323machine # [ 0.359670] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned324machine # [ 0.359689] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned325machine # [ 0.359707] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned326machine # [ 0.359725] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned327machine # [ 0.359744] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned328machine # [ 0.359762] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned329machine # [ 0.359781] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned330machine # [ 0.359801] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned331machine # [ 0.359820] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned332machine # [ 0.359839] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned333machine # [ 0.359858] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned334machine # [ 0.359877] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned335machine # [ 0.359897] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned336machine # [ 0.359915] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned337machine # [ 0.359934] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned338machine # [ 0.359952] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned339machine # [ 0.359970] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned340machine # [ 0.359989] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned341machine # [ 0.360012] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]342machine # [ 0.360017] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]343machine # [ 0.360020] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]344machine # [ 0.361143] pci 0000:00:07.0: enabling device (0000 -> 0002)345machine # [ 0.390597] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)346machine # [ 0.392790] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)347machine # [ 0.394776] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)348machine # [ 0.408698] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)349machine # [ 0.410884] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)350machine # [ 0.413142] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)351machine # [ 0.415113] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)352machine # [ 0.424764] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)353machine # [ 0.426686] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)354machine # [ 0.428735] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)355machine # [ 0.431090] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)356machine # [ 0.443717] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled357machine # [ 0.452571] msm_serial: driver initialized358machine # [ 0.452776] SuperH (H)SCI(F) driver initialized359machine # [ 0.452837] STM32 USART driver initialized360machine # [ 0.470803] loop: module loaded361machine # [ 0.471037] virtio_blk virtio2: 2/0/0 default/read/poll queues362machine # [ 0.472386] virtio_blk virtio2: [vda] 16777216 512-byte logical blocks (8.59 GB/8.00 GiB)363machine # [ 0.474355] megasas: 07.734.00.00-rc1364machine # [ 0.475086] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]365machine # [ 0.482287] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000366machine # [ 0.482335] Intel/Sharp Extended Query Table at 0x0031367machine # [ 0.484140] Using buffer write method368machine # [ 0.484203] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]369machine # [ 0.486455] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000370machine # [ 0.486478] Intel/Sharp Extended Query Table at 0x0031371machine # [ 0.488105] Using buffer write method372machine # [ 0.488125] Concatenating MTD devices:373machine # [ 0.488127] (0): "0.flash"374machine # [ 0.488130] (1): "0.flash"375machine # [ 0.488132] into device "0.flash"376machine # [ 0.725583] Freeing initrd memory: 25244K377machine # [ 0.736046] tun: Universal TUN/TAP device driver, 1.6378machine # [ 0.741088] thunder_xcv, ver 1.0379machine # [ 0.741148] thunder_bgx, ver 1.0380machine # [ 0.741193] nicpf, ver 1.0381machine # [ 0.742155] e1000: Intel(R) PRO/1000 Network Driver382machine # [ 0.742161] e1000: Copyright (c) 1999-2006 Intel Corporation.383machine # [ 0.742198] e1000e: Intel(R) PRO/1000 Network Driver384machine # [ 0.742207] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.385machine # [ 0.742286] igb: Intel(R) Gigabit Ethernet Network Driver386machine # [ 0.742291] igb: Copyright (c) 2007-2014 Intel Corporation.387machine # [ 0.742325] igbvf: Intel(R) Gigabit Virtual Function Network Driver388machine # [ 0.742332] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.389machine # [ 0.742566] sky2: driver version 1.30390machine # [ 0.745324] usbcore: registered new interface driver usb-storage391machine # [ 0.745462] usbcore: registered new interface driver usbserial_generic392machine # [ 0.745481] usbserial: USB Serial support registered for generic393machine # [ 0.746471] hv_vmbus: registering driver hyperv_keyboard394machine # [ 0.747941] rtc-pl031 9010000.pl031: registered as rtc0395machine # [ 0.747973] rtc-pl031 9010000.pl031: setting system clock to 2026-11-12T11:49:47 UTC (1794484187)396machine # [ 0.748488] i2c_dev: i2c /dev entries driver397machine # [ 0.752125] ehci-pci 0000:00:07.0: EHCI Host Controller398machine # [ 0.752157] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1399machine # [ 0.752379] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000400machine # [ 0.753639] sdhci: Secure Digital Host Controller Interface driver401machine # [ 0.753648] sdhci: Copyright(c) Pierre Ossman402machine # [ 0.754108] Synopsys Designware Multimedia Card Interface Driver403machine # [ 0.754736] sdhci-pltfm: SDHCI platform and OF driver helper404machine # [ 0.757334] hid: raw HID events driver (C) Jiri Kosina405machine # [ 0.757769] usbcore: registered new interface driver usbhid406machine # [ 0.757775] usbhid: USB HID core driver407machine # [ 0.763979] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available408machine # [ 0.765464] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00409machine # [ 0.766477] drop_monitor: Initializing network drop monitor service410machine # [ 0.766654] NET: Registered PF_INET6 protocol family411machine # [ 0.767091] hub 1-0:1.0: USB hub found412machine # [ 0.769851] hub 1-0:1.0: 6 ports detected413machine # [ 0.770281] Segment Routing with IPv6414machine # [ 0.770304] In-situ OAM (IOAM) with IPv6415machine # [ 0.770372] NET: Registered PF_PACKET protocol family416machine # [ 0.770515] 9pnet: Installing 9P2000 support417machine # [ 0.770577] Key type dns_resolver registered418machine # [ 0.781127] registered taskstats version 1419machine # [ 0.781424] Loading compiled-in X.509 certificates420machine # [ 0.797087] Demotion targets for Node 0: null421machine # [ 0.797316] Key type .fscrypt registered422machine # [ 0.797322] Key type fscrypt-provisioning registered423machine # [ 0.797466] ima: No TPM chip found, activating TPM-bypass!424machine # [ 0.797492] ima: Allocated hash algorithm: sha1425machine # [ 0.797519] ima: No architecture policies found426machine # [ 0.798900] input: gpio-keys as /devices/platform/gpio-keys/input/input0427machine # [ 0.822514] clk: Disabling unused clocks428machine # [ 0.822534] PM: genpd: Disabling unused power domains429machine # [ 0.828433] Freeing unused kernel memory: 7808K430machine # [ 0.828649] Run /init as init process431machine # [ 0.851855] systemd[1]: Successfully made /usr/ read-only.432machine # [ 1.015181] usb 1-1: new high-speed USB device number 2 using ehci-pci433machine # [ 1.165057] 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/input1434machine # [ 1.186239] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)435machine # [ 1.186271] systemd[1]: Detected virtualization qemu.436machine # [ 1.186318] systemd[1]: Detected architecture arm64.437machine # [ 1.186327] systemd[1]: Running in initrd.438machine # [ 1.186893] systemd[1]: Initializing machine ID from random generator.439machine # [ 1.187055] systemd[1]: Hostname set to <machine>.440machine # [ 1.255423] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0441machine # [ 1.311495] systemd[1]: bpf-restrict-fs: LSM BPF program attached442machine # [ 1.361629] systemd[1]: Queued start job for default target Initrd Default Target.443machine # [ 1.370194] systemd[1]: Created slice Slice /system/modprobe.444machine # [ 1.370508] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.445machine # [ 1.370558] systemd[1]: Expecting device /dev/disk/by-label/nixos...446machine # [ 1.370589] systemd[1]: Reached target Path Units.447machine # [ 1.370613] systemd[1]: Reached target Slice Units.448machine # [ 1.370633] systemd[1]: Reached target Swaps.449machine # [ 1.370654] systemd[1]: Reached target Timer Units.450machine # [ 1.370867] systemd[1]: Listening on D-Bus System Message Bus Socket.451machine # [ 1.371069] systemd[1]: Listening on Journal Socket (/dev/log).452machine # [ 1.371324] systemd[1]: Listening on Journal Sockets.453machine # [ 1.371449] systemd[1]: Listening on udev Kernel Socket.454machine # [ 1.371769] systemd[1]: Listening on udev Varlink Socket.455machine # [ 1.371796] systemd[1]: Reached target Socket Units.456machine # [ 1.374054] systemd[1]: Starting Create List of Static Device Nodes...457machine # [ 1.374154] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs458machine # [ 1.379260] usb 1-2: new high-speed USB device number 3 using ehci-pci459machine # [ 1.382499] systemd[1]: Mounting Kernel Configuration File System...460machine # [ 1.400508] systemd[1]: Starting Journal Service...461machine # [ 1.403352] systemd[1]: Starting Load Kernel Modules...462machine # [ 1.403515] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os463machine # [ 1.411505] systemd[1]: Starting Coldplug All udev Devices...464machine # [ 1.419461] systemd[1]: Finished Create List of Static Device Nodes.465machine # [ 1.420792] systemd[1]: Mounted Kernel Configuration File System.466machine # [ 1.435457] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...467machine # [ 1.435859] systemd-journald[79]: Collecting audit messages is disabled.468machine # [ 1.469149] virtio_dma_buf: module verification failed: signature and/or required key missing - tainting kernel469machine # [ 1.479571] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.470machine # [ 1.491677] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0471machine # [ 1.491926] [drm] features: -virgl +edid -resource_blob -host_visible472machine # [ 1.491929] [drm] features: -context_init473machine # [ 1.492271] systemd[1]: Starting Create Static Device Nodes in /dev...474machine # [ 1.494403] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.475machine # [ 1.494656] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev476machine # [ 1.501364] [drm] number of scanouts: 1477machine # [ 1.501377] [drm] number of cap sets: 0478machine # [ 1.502256] systemd-modules-load[80]: Using 2 probe threads479machine # [ 1.507642] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic480machine # [ 1.507655] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0481machine # [ 1.508618] systemd[1]: Started Journal Service.482machine # [ 1.509084] systemd-modules-load[80]: Module 'virtio_balloon' is built in[ 1.517861] Console: switching to colour frame buffer device 160x50483machine # 484machine # [ 1.520524] systemd-modules-load[80]: Module 'virtio_console' is built in485machine # [ 1.521825] systemd-modules-load[80]: Inserted module 'dm_mod'486machine # [ 1.530563] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device487machine # [ 1.526100] systemd-modules-load[80]: Module 'virtio_rng' is built in488machine # [ 1.528278] systemd[1]: Finished Create Static Device Nodes in /dev.489machine # [ 1.529928] systemd[1]: Reached target Preparation for Local File Systems.490machine # [ 1.536378] systemd[1]: Reached target Local File Systems.491machine # [ 1.537486] systemd[1]: Starting Create System Files and Directories...492machine # [ 1.538469] systemd[1]: Starting Rule-based Manager for Device Events and Files...493machine # [ 1.540756] systemd-modules-load[80]: Inserted module 'virtio_gpu'494machine # [ 1.550147] 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/input2495machine # [ 1.550479] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0496machine # [ 1.555962] systemd[1]: Finished Load Kernel Modules.497machine # [ 1.568382] systemd[1]: Starting Apply Kernel Variables...498machine # [ 1.578984] systemd[1]: Finished Create System Files and Directories.499machine # [ 1.585155] systemd[1]: Finished Apply Kernel Variables.500machine # [ 1.600285] systemd-udevd[90]: Using default interface naming scheme 'v261'.501machine # [ 1.611815] systemd[1]: Started Rule-based Manager for Device Events and Files.502machine # [ 1.676697] systemd[1]: Starting Virtual Console Setup...503machine # [ 1.700965] systemd-vconsole-setup[114]: Configuration of first virtual console was skipped, ignoring remaining ones.504machine # [ 1.705524] systemd[1]: Finished Virtual Console Setup.505machine # [ 2.147356] systemd[1]: Finished Coldplug All udev Devices.506machine # [ 2.149277] systemd[1]: Reached target System Initialization.507machine # [ 2.150334] systemd[1]: Reached target Basic System.508machine # [ 2.284559] (udev-worker)[125]: Network interface NamePolicy= disabled on kernel command line.509machine # [ 2.321013] systemd[1]: Found device /dev/disk/by-label/nixos.510machine # [ 2.322093] systemd[1]: Reached target Initrd Root Device.511machine # [ 2.324761] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...512machine # [ 2.334250] (udev-worker)[105]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.513machine # [ 2.337682] (udev-worker)[105]: Network interface NamePolicy= disabled on kernel command line.514machine # [ 2.379342] systemd-fsck[131]: nixos: clean, 12/524288 files, 58513/2097152 blocks515machine # [ 2.448777] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.516machine # [ 2.454613] systemd[1]: Mounting /sysroot...517machine # [ 2.495272] EXT4-fs (vda): mounted filesystem 6fa3e7fb-60a8-4689-8d1e-7366174acbda r/w with ordered data mode. Quota mode: none.518machine # [ 2.492010] systemd[1]: Mounted /sysroot.519machine # [ 2.497418] systemd[1]: Reached target Initrd Root File System.520machine # [ 2.503818] systemd[1]: Mounting /sysroot/nix/.ro-store...521machine # [ 2.507425] systemd[1]: Mounting /sysroot/nix/.rw-store...522machine # [ 2.520351] systemd[1]: Mounting /sysroot/run...523machine # [ 2.547412] systemd[1]: Mounting /sysroot/tmp/shared...524machine # [ 2.571038] fuse: init (API version 7.45)525machine # [ 2.568169] systemd[1]: Mounting /sysroot/tmp/xchg...526machine # [ 2.582680] virtiofs virtio6: discovered new tag: nix-store527machine # [ 2.579613] systemd[1]: Starting Mountpoints Configured in the Real Root...528machine # [ 2.588248] virtiofs virtio6: virtio_fs_setup_dax: No cache capability529machine # [ 2.588454] systemd[1]: Mounted /sysroot/nix/.rw-store.530machine # [ 2.589290] systemd[1]: Mounted /sysroot/run.531machine # [ 2.605326] virtiofs virtio7: discovered new tag: shared532machine # [ 2.606172] virtiofs virtio7: virtio_fs_setup_dax: No cache capability533machine # [ 2.620978] virtiofs virtio8: discovered new tag: xchg534machine # [ 2.621865] virtiofs virtio8: virtio_fs_setup_dax: No cache capability535machine # [ 2.619048] systemd-sysroot-fstab-check[146]: /sysroot should be mounted in the initrd, will request daemon-reload.536machine # [ 2.626713] systemd[1]: Starting rw-sysroot-nix-store.service...537machine # [ 2.635989] systemd[1]: Mounted /sysroot/tmp/shared.538machine # [ 2.637051] systemd[1]: Mounted /sysroot/nix/.ro-store.539machine # [ 2.637944] systemd[1]: Mounted /sysroot/tmp/xchg.540machine # [ 2.643348] systemd[1]: Reload requested from client PID 146 ('systemd-sysroot') (unit initrd-parse-etc.service)...541machine # [ 2.645306] systemd[1]: Reloading...542machine # [ 2.768304] systemd[1]: Reloading finished in 126 ms.543machine # [ 2.816696] systemd-sysroot-fstab-check[146]: Requesting initrd-fs.target/start/replace...544machine # [ 2.820297] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.545machine # [ 2.824348] systemd[1]: Finished rw-sysroot-nix-store.service.546machine # [ 2.826752] systemd-sysroot-fstab-check[146]: Requesting swap.target/start/replace...547machine # [ 2.829992] systemd[1]: Starting rw-sysroot-nix-store.service...548machine # [ 2.832195] systemd[1]: initrd-parse-etc.service: Deactivated successfully.549machine # [ 2.834686] systemd[1]: Finished Mountpoints Configured in the Real Root.550machine # [ 2.836819] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.551machine # [ 2.854957] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.552machine # [ 2.857420] systemd[1]: Finished rw-sysroot-nix-store.service.553machine # [ 3.232526] (udev-worker)[103]: mtd0ro: Failed to find and pin callout binary "/nix/store/rzzrvlm7r31iq3im3h66nhxc2zh996l9-systemd-262/lib/udev/mtd_probe": No such file or directory554machine # [ 3.236312] (udev-worker)[103]: 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 directory555machine # [ 3.255804] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.556machine # [ 3.257991] systemd[1]: Stopped Virtual Console Setup.557machine # [ 3.259398] systemd[1]: Stopping Virtual Console Setup...558machine # [ 3.260861] systemd[1]: Starting Virtual Console Setup...559machine # [ 3.271125] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.560machine # [ 3.272446] systemd[1]: Stopped Virtual Console Setup.561machine # [ 3.276262] systemd[1]: Starting Virtual Console Setup...562machine # [ 3.309581] systemd-vconsole-setup[178]: Configuration of first virtual console was skipped, ignoring remaining ones.563machine # [ 3.312277] systemd[1]: Finished Virtual Console Setup.564machine # [ 3.410097] systemd[1]: Mounting /sysroot/nix/store...565machine # [ 3.461294] systemd[1]: Mounted /sysroot/nix/store.566machine # [ 3.462694] systemd[1]: Reached target Initrd File Systems.567machine # [ 3.469912] systemd[1]: Starting Find NixOS closure...568machine # [ 3.472220] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...569machine # [ 3.508701] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.570machine # [ 3.512702] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.571machine # [ 3.518459] systemd[1]: Finished Find NixOS closure.572machine # [ 3.519765] systemd[1]: Reached target Initrd Default Target.573machine # [ 3.522400] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...574machine # [ 3.556361] systemd[1]: Stopped target Initrd Default Target.575machine # [ 3.558801] systemd[1]: Stopped target Basic System.576machine # [ 3.560803] systemd[1]: Stopped target Initrd Root Device.577machine # [ 3.562159] systemd[1]: Stopped target Path Units.578machine # [ 3.563336] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.579machine # [ 3.565209] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.580machine # [ 3.567075] systemd[1]: Stopped target Slice Units.581machine # [ 3.568312] systemd[1]: Stopped target Socket Units.582machine # [ 3.569514] systemd[1]: Stopped target System Initialization.583machine # [ 3.570909] systemd[1]: Stopped target Swaps.584machine # [ 3.571988] systemd[1]: Stopped target Timer Units.585machine # [ 3.574793] systemd[1]: dbus.socket: Deactivated successfully.586machine # [ 3.577406] systemd[1]: Closed D-Bus System Message Bus Socket.587machine # [ 3.578710] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.588machine # [ 3.583287] systemd[1]: Stopped Find NixOS closure.589machine # [ 3.584403] systemd[1]: Starting rw-sysroot-nix-store.service...590machine # [ 3.585623] systemd[1]: systemd-sysctl.service: Deactivated successfully.591machine # [ 3.586921] systemd[1]: Stopped Apply Kernel Variables.592machine # [ 3.587998] systemd[1]: systemd-modules-load.service: Deactivated successfully.593machine # [ 3.590068] systemd[1]: Stopped Load Kernel Modules.594machine # [ 3.594813] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.595machine # [ 3.596889] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.596machine # [ 3.599262] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.597machine # [ 3.602966] systemd[1]: Stopped Create System Files and Directories.598machine # [ 3.604492] systemd[1]: Stopped target Local File Systems.599machine # [ 3.606204] systemd[1]: Stopped target Preparation for Local File Systems.600machine # [ 3.607572] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.601machine # [ 3.609101] systemd[1]: Stopped Coldplug All udev Devices.602machine # [ 3.610233] systemd[1]: Stopping Rule-based Manager for Device Events and Files...603machine # [ 3.611617] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.604machine # [ 3.613346] systemd[1]: Stopped Virtual Console Setup.605machine # [ 3.614413] systemd[1]: initrd-cleanup.service: Deactivated successfully.606machine # [ 3.615622] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.607machine # [ 3.616871] systemd[1]: systemd-udevd.service: Deactivated successfully.608machine # [ 3.618075] systemd[1]: Stopped Rule-based Manager for Device Events and Files.609machine # [ 3.619346] systemd[1]: systemd-udevd.service: Consumed 1.865s CPU time over 2.072s wall clock time, 31.9M memory peak.610machine # [ 3.621257] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.611machine # [ 3.622567] systemd[1]: Finished rw-sysroot-nix-store.service.612machine # [ 3.623585] systemd[1]: systemd-udevd-varlink.socket: Deactivated successfully.613machine # [ 3.624910] systemd[1]: Closed udev Varlink Socket.614machine # [ 3.625790] systemd[1]: Starting Cleanup udev Database...615machine # [ 3.626736] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.616machine # [ 3.628226] systemd[1]: Stopped Create Static Device Nodes in /dev.617machine # [ 3.629287] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.618machine # [ 3.630676] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.619machine # [ 3.631816] systemd[1]: kmod-static-nodes.service: Deactivated successfully.620machine # [ 3.633017] systemd[1]: Stopped Create List of Static Device Nodes.621machine # [ 3.677033] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.622machine # [ 3.678965] systemd[1]: Finished Cleanup udev Database.623machine # [ 3.680256] systemd[1]: Reached target Switch Root.624machine # [ 3.681656] systemd[1]: Starting NixOS Activation...625machine # [ 3.767094] initrd-nixos-activation-start[201]: booting system configuration /nix/store/8s3psb7bl59psh19j3h9r70x07wzhccv-nixos-system-machine-test626machine # [ 3.804892] initrd-nixos-activation-start[201]: running activation script...627machine # [ 4.094112] initrd-nixos-activation-start[224]: setting up /etc...628machine # [ 4.230301] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.629machine # [ 4.232169] systemd[1]: Finished NixOS Activation.630machine # [ 4.233282] systemd[1]: Starting Switch Root...631machine # [ 4.264568] systemd[1]: Switching root.632machine # [ 4.382234] systemd-journald[79]: Received SIGTERM from PID 1 (systemd).633machine # [ 4.941118] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)634machine # [ 4.941183] systemd[1]: Detected virtualization qemu.635machine # [ 4.941239] systemd[1]: Detected architecture arm64.636machine # [ 4.941345] systemd[1]: Detected first boot.637machine # [ 4.952727] systemd[1]: Initializing machine ID from random generator.638machine # [ 5.083230] systemd[1]: bpf-restrict-fs: LSM BPF program attached639machine # [ 5.209182] systemd[1]: Applying preset policy.640machine # [ 5.443201] systemd[1]: Populated /etc with preset unit settings.641machine # [ 5.663632] systemd[1]: initrd-switch-root.service: Deactivated successfully.642machine # [ 5.664201] systemd[1]: Stopped initrd-switch-root.service.643machine # [ 5.666803] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.644machine # [ 5.670159] systemd[1]: Created slice Slice /system/getty.645machine # [ 5.672872] systemd[1]: Created slice User and Session Slice.646machine # [ 5.673591] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.647machine # [ 5.674275] systemd[1]: Started Forward Password Requests to Wall Directory Watch.648machine # [ 5.674894] systemd[1]: Expecting device /dev/hvc0...649machine # [ 5.675543] systemd[1]: Expecting device /dev/ttyAMA0...650machine # [ 5.676230] systemd[1]: Reached target Local Encrypted Volumes.651machine # [ 5.676879] systemd[1]: Stopped target initrd-fs.target.652machine # [ 5.677533] systemd[1]: Stopped target initrd-root-fs.target.653machine # [ 5.678264] systemd[1]: Stopped target initrd-switch-root.target.654machine # [ 5.678933] systemd[1]: Reached target Virtual Machines and Containers.655machine # [ 5.679560] systemd[1]: Reached target Path Units.656machine # [ 5.680175] systemd[1]: Reached target Remote File Systems.657machine # [ 5.680898] systemd[1]: Reached target Slice Units.658machine # [ 5.681514] systemd[1]: Reached target Swaps.659machine # [ 5.683487] systemd[1]: Listening on Query the User Interactively for a Password.660machine # [ 5.685757] systemd[1]: Listening on Process Core Dump Socket.661machine # [ 5.688654] systemd[1]: Listening on Credential Encryption/Decryption.662machine # [ 5.690190] systemd[1]: Listening on Factory Reset Management.663machine # [ 5.690821] systemd[1]: Listening on Hostname Service Socket.664machine # [ 5.696001] systemd[1]: Starting Journal Log Access Socket...665machine # [ 5.699523] systemd[1]: Listening on Journal Audit Socket.666machine # [ 5.701545] systemd[1]: Listening on Console Output Muting Service Socket.667machine # [ 5.702416] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.668machine # [ 5.703001] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os669machine # [ 5.703559] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki670machine # [ 5.709434] systemd[1]: Listening on Disk Repartitioning Service Socket.671machine # [ 5.710153] systemd[1]: Listening on udev Varlink Socket.672machine # [ 5.715338] systemd[1]: Mounting Huge Pages File System...673machine # [ 5.721962] systemd[1]: Mounting POSIX Message Queue File System...674machine # [ 5.731298] systemd[1]: Mounting Kernel Debug File System...675machine # [ 5.746788] systemd[1]: Mounting Kernel Trace File System...676machine # [ 5.757125] systemd[1]: Starting Create List of Static Device Nodes...677machine # [ 5.757925] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs678machine # [ 5.765940] systemd[1]: Mounting Kernel Configuration File System...679machine # [ 5.772740] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm680machine # [ 5.773276] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore681machine # [ 5.773768] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse682machine # [ 5.787549] systemd[1]: Mounting FUSE Control File System...683machine # [ 5.792576] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67684machine # [ 5.801642] systemd[1]: Starting Journal Service...685machine # [ 5.816807] systemd[1]: Starting Load Kernel Modules...686machine # [ 5.822634] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...687machine # [ 5.832412] systemd[1]: Starting Remount Root and Kernel File Systems...688machine # [ 5.833031] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os689machine # [ 5.856942] systemd[1]: Starting Coldplug All udev Devices...690machine # [ 5.865479] systemd[1]: Listening on Journal Log Access Socket.691machine # [ 5.866560] systemd[1]: Mounted Huge Pages File System.692machine # [ 5.867983] systemd[1]: Mounted POSIX Message Queue File System.693machine # [ 5.869585] systemd[1]: Mounted Kernel Debug File System.694machine # [ 5.870342] systemd[1]: Mounted Kernel Trace File System.695machine # [ 5.873603] systemd[1]: Finished Create List of Static Device Nodes.696machine # [ 5.874593] systemd[1]: Mounted Kernel Configuration File System.697machine # [ 5.875445] systemd[1]: Mounted FUSE Control File System.698machine # [ 5.881750] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...699machine # [ 5.906024] systemd-journald[295]: Collecting audit messages is enabled.700machine # [ 5.922111] systemd[1]: Started Journal Service.701machine # [ 5.916621] systemd[1]: Queued start job for default target Multi-User System.702machine # [ 5.919799] systemd[1]: systemd-journald.service: Deactivated successfully.703machine # [ 5.924979] systemd-modules-load[296]: Using 2 probe threads704machine # [ 5.929973] systemd-modules-load[296]: Module 'atkbd' is built in705machine # [ 5.931294] systemd-modules-load[296]: Module 'loop' is built in706machine # [ 5.949716] EXT4-fs (vda): re-mounted 6fa3e7fb-60a8-4689-8d1e-7366174acbda.707machine # [ 5.946536] systemd[1]: Finished Load Kernel Modules.708machine # [ 5.954150] systemd[1]: Starting Apply Kernel Variables...709machine # [ 5.961157] systemd-oomd[298]: No swap; memory pressure usage will be degraded710machine # [ 5.969810] systemd[1]: Finished Remount Root and Kernel File Systems.711machine # [ 5.972679] systemd[1]: Listening on Disk Image Download Service Socket.712machine # [ 5.977671] systemd[1]: Starting Flush Journal to Persistent Storage...713machine # [ 5.981849] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore714machine # [ 5.984163] systemd[1]: Starting Load/Save OS Random Seed...715machine # [ 5.989277] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os716machine # [ 5.996677] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.717machine # [ 6.033317] systemd-journald[295]: Received client request to flush runtime journal.718machine # [ 6.070888] systemd[1]: Finished Load/Save OS Random Seed.719machine # [ 6.072970] systemd[1]: Reached target First Boot Complete.720machine # [ 6.073954] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.721machine # [ 6.075059] systemd[1]: Starting Create Static Device Nodes in /dev...722machine # [ 6.076406] systemd[1]: Finished Apply Kernel Variables.723machine # [ 6.085569] systemd[1]: Finished Flush Journal to Persistent Storage.724machine # [ 6.115350] systemd[1]: Finished Create Static Device Nodes in /dev.725machine # [ 6.116687] systemd[1]: Reached target Preparation for Local File Systems.726machine # [ 6.120179] systemd[1]: Starting Rule-based Manager for Device Events and Files...727machine # [ 6.174927] systemd-udevd[325]: Using default interface naming scheme 'v261'.728machine # [ 6.206669] systemd[1]: Started Rule-based Manager for Device Events and Files.729machine # [ 6.593217] systemd[1]: Finished Coldplug All udev Devices.730machine # [ 6.637493] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs731machine # [ 6.653240] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse732machine # [ 6.659068] systemd[1]: Mounting /run/wrappers...733machine # [ 6.693607] systemd[1]: Mounted /run/wrappers.734machine # [ 6.696280] systemd[1]: Reached target Local File Systems.735machine # [ 6.700365] systemd[1]: Listening on Boot Loader Control Service Socket.736machine # [ 6.710386] systemd[1]: Starting register-nix-paths.service...737machine # [ 6.711562] systemd[1]: Starting Create SUID/SGID Wrappers...738machine # [ 6.719022] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.739machine # [ 6.721773] systemd[1]: Starting Save Transient machine-id to Disk...740machine # [ 6.724161] systemd[1]: Starting Create System Files and Directories...741machine # [ 6.784477] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.742machine # [ 6.823297] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.743machine # [ 6.830405] systemd[1]: Finished Save Transient machine-id to Disk.744machine # [ 6.836251] systemd[1]: Finished Create System Files and Directories.745machine # [ 6.842037] systemd[1]: Starting Rebuild Journal Catalog...746machine # [ 6.846287] systemd[1]: Starting Record System Boot/Shutdown in UTMP...747machine # [ 6.866084] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.748machine # [ 6.904262] systemd[1]: Finished Record System Boot/Shutdown in UTMP.749machine # [ 6.940867] systemd[1]: Finished Rebuild Journal Catalog.750machine # [ 6.951623] (udev-worker)[333]: Network interface NamePolicy= disabled on kernel command line.751machine # [ 6.953875] systemd[1]: Starting Update is Completed...752machine # [ 7.001950] systemd[1]: Finished Update is Completed.753machine # [ 7.053287] (udev-worker)[336]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.754machine # [ 7.058764] (udev-worker)[336]: Network interface NamePolicy= disabled on kernel command line.755machine # [ 7.197585] systemd[1]: Finished register-nix-paths.service.756machine # [ 7.199672] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.757machine # [ 7.201860] systemd[1]: Finished Create SUID/SGID Wrappers.758machine # [ 7.207822] systemd[1]: Reached target System Initialization.759machine # [ 7.208952] systemd[1]: Started Discard unused filesystem blocks once a week.760machine # [ 7.214179] systemd[1]: Started Daily Cleanup of Temporary Directories.761machine # [ 7.216647] systemd[1]: Reached target Timer Units.762machine # [ 7.221292] systemd[1]: Listening on D-Bus System Message Bus Socket.763machine # [ 7.225040] systemd[1]: Listening on Nix Daemon Socket.764machine # [ 7.227144] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.765machine # [ 7.236351] systemd[1]: Reached target Socket Units.766machine # [ 7.239678] systemd[1]: Reached target Basic System.767machine # [ 7.242455] systemd[1]: Started backdoor.service.768machine # [ 7.244973] systemd[1]: Starting Import lastlog data into lastlog2 database...769machine # [ 7.252582] systemd[1]: Starting Name Service Cache Daemon (nsncd)...770machine # [ 7.268870] systemd[1]: Starting Post-Boot Actions...771machine # [ 7.270195] systemd[1]: Started Reset console on configuration changes.772machine # [ 7.276397] systemd[1]: Starting resolvconf update...773machine # [ 7.281818] systemd[1]: Starting D-Bus System Message Bus...774machine # [ 7.286452] systemd[1]: Condition check resulted in Virtio network device being skipped.775machine # [ 7.312980] systemd[1]: Started Name Service Cache Daemon (nsncd).776machine # [ 7.316388] systemd[1]: Reached target Host and Network Name Lookups.777machine # [ 7.320435] systemd[1]: Reached target User and Group Name Lookups.778machine # connecting to host...779machine # [ 7.325688] nsncd[429]: Nov 12 11:49:54.077 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"780machine # [ 7.336312] systemd[1]: Starting User Login Management...781machine # [ 7.354320] systemd[1]: Finished Post-Boot Actions.782[8.07s] machine: Guest shell says: b'Spawning backdoor root shell...\n'783[8.08s] machine: connected to guest root shell784[8.08s] machine: (connecting took 7.69 seconds)785[8.08s] machine: (finished: waiting for the VM to finish booting, in 8.08 seconds)786machine # [ 7.420878] dbus-broker-launch[434]: Looking up NSS user entry for 'systemd-timesync'...787machine # [ 7.430060] mousedev: PS/2 mouse device common for all mice788machine # [ 7.427980] systemd[1]: Finished Import lastlog data into lastlog2 database.789machine # [ 7.429993] dbus-broker-launch[434]: NSS returned no entry for 'systemd-timesync'790machine # [ 7.436165] dbus-broker-launch[434]: Invalid user-name in /nix/store/zwpdq5dl6mgp5cnkswh4wmrmps0m71lm-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"791machine # [ 7.456398] systemd[1]: Started D-Bus System Message Bus.792machine # [ 7.502619] dbus-broker-launch[434]: Ready793machine # [ 7.530178] systemd-logind[440]: Watching system buttons on /dev/input/event0 (gpio-keys)794machine # [ 7.536508] systemd-logind[440]: New seat seat0.795machine # [ 7.537487] systemd[1]: Started User Login Management.796machine # [ 7.540095] systemd[1]: Starting linger-users.service...797machine # [ 7.554349] systemd-logind[440]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)798machine # [ 7.580603] systemd[1]: Stopped target Host and Network Name Lookups.799machine # [ 7.581752] systemd[1]: Stopping Host and Network Name Lookups...800machine # [ 7.582639] systemd[1]: Stopped target User and Group Name Lookups.801machine # [ 7.583529] systemd[1]: Stopping User and Group Name Lookups...802machine # [ 7.589874] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...803machine # [ 7.590890] systemd[1]: nscd.service: Deactivated successfully.804machine # [ 7.594444] systemd[1]: Stopped Name Service Cache Daemon (nsncd).805machine # [ 7.598916] systemd[1]: Starting Name Service Cache Daemon (nsncd)...806machine # [ 7.617531] systemd[1]: linger-users.service: Deactivated successfully.807machine # [ 7.625341] systemd[1]: Finished linger-users.service.808machine # [ 7.650082] systemd[1]: Finished resolvconf update.809machine # [ 7.657458] systemd[1]: Reached target Preparation for Network.810machine # [ 7.658836] systemd[1]: Starting DHCP Client...811machine # [ 7.664799] systemd[1]: Starting Address configuration of eth1...812machine # [ 7.665749] systemd[1]: Starting Extra networking commands....813machine # [ 7.671361] systemd[1]: Started Name Service Cache Daemon (nsncd).814machine # [ 7.672376] systemd[1]: Reached target Host and Network Name Lookups.815machine # [ 7.673328] systemd[1]: Reached target User and Group Name Lookups.816machine # [ 7.687076] nsncd[514]: Nov 12 11:49:54.444 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"817machine # [ 7.770391] network-addresses-eth1-start[528]: adding address 192.168.1.1/24... done818machine # [ 7.784197] network-addresses-eth1-start[528]: adding address 2001:db8:1::1/64... done819machine # [ 7.807530] systemd[1]: Finished Address configuration of eth1.820machine # [ 7.817710] dhcpcd[543]: dhcpcd-10.3.2 starting821machine # [ 7.820970] dhcpcd[585]: dev: loaded udev822machine # [ 7.844812] 8021q: 802.1Q VLAN Support v1.8823machine # [ 7.845199] 8021q: adding VLAN 0 to HW filter on device eth1824machine # [ 7.876113] systemd[1]: Finished Extra networking commands..825machine # [ 7.877097] systemd[1]: Reached target Network.826machine # [ 7.884130] systemd[1]: Starting PostgreSQL Server...827machine # [ 7.888120] systemd[1]: Started RustFS S3-compatible object storage.828machine # [ 7.896148] systemd[1]: Starting Setup RustFS bucket...829machine # [ 7.905218] cfg80211: Loading compiled-in X.509 certificates for regulatory database830machine # [ 7.906050] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'831machine # [ 7.906540] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'832machine # [ 7.910924] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2833machine # [ 7.911293] cfg80211: failed to load regulatory.db834machine # [ 7.908139] systemd[1]: Starting Permit User Sessions...835machine # [ 7.949718] systemd[1]: Finished Permit User Sessions.836machine # [ 7.952547] systemd[1]: Started Getty on tty1.837machine # [ 7.953548] systemd[1]: Reached target Login Prompts.838machine # [ 8.047720] dhcpcd[585]: eth0: waiting for carrier[ 8.052996] 8021q: adding VLAN 0 to HW filter on device eth0839machine # 840machine # [ 8.049481] dhcpcd[585]: eth0: carrier acquired841machine # [ 8.073172] dhcpcd[585]: DUID 00:01:00:01:32:88:64:62:52:54:00:12:34:56842machine # [ 8.075051] dhcpcd[585]: eth0: IAID 00:12:34:56843machine # [ 8.075771] dhcpcd[585]: eth0: adding address fe80::5054:ff:fe12:3456844machine # [ 8.209673] postgresql-pre-start[634]: The files belonging to this database system will be owned by user "postgres".845machine # [ 8.211295] postgresql-pre-start[634]: This user must also own the server process.846machine # [ 8.217436] postgresql-pre-start[634]: The database cluster will be initialized with locale "en_US.UTF-8".847machine # [ 8.218805] postgresql-pre-start[634]: The default database encoding has accordingly been set to "UTF8".848machine # [ 8.223541] postgresql-pre-start[634]: The default text search configuration will be set to "english".849machine # [ 8.226134] postgresql-pre-start[634]: Data page checksums are enabled.850machine # [ 8.227142] postgresql-pre-start[634]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok851machine # [ 8.229590] postgresql-pre-start[634]: creating subdirectories ... ok852machine # [ 8.230955] postgresql-pre-start[634]: selecting dynamic shared memory implementation ... posix853machine # [ 8.346489] postgresql-pre-start[634]: selecting default "max_connections" ... 100854machine # [ 8.452401] postgresql-pre-start[634]: selecting default "shared_buffers" ... 128MB855machine # [ 8.874058] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input3856machine # [ 9.145943] systemd[1]: Starting Virtual Console Setup...857machine # [ 9.174313] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.858machine # [ 9.180549] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.859machine # [ 9.182674] systemd[1]: Stopped Virtual Console Setup.860machine # [ 9.186777] systemd[1]: Starting Virtual Console Setup...861machine # [ 9.215118] systemd-logind[440]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)862machine # [ 9.319855] postgresql-pre-start[634]: selecting default time zone ... UTC863machine # [ 9.321417] postgresql-pre-start[634]: creating configuration files ... ok864machine # [ 9.349574] systemd-vconsole-setup[677]: Configuration of first virtual console was skipped, ignoring remaining ones.865machine # [ 9.356155] systemd[1]: Finished Virtual Console Setup.866machine # [ 9.500585] dhcpcd[585]: eth0: soliciting a DHCP lease867machine # [ 9.504699] dhcpcd[585]: eth0: offered 10.0.2.15 from 10.0.2.2868machine # [ 9.524322] dhcpcd[585]: eth0: probing address 10.0.2.15/24869machine # [ 9.545518] postgresql-pre-start[634]: running bootstrap script ... ok870machine # [ 10.034060] dhcpcd[585]: eth0: soliciting an IPv6 router871machine # [ 10.036228] dhcpcd[585]: eth0: Router Advertisement from fe80::2872machine # [ 10.037747] dhcpcd[585]: eth0: adding address fec0::5054:ff:fe12:3456/64873machine # [ 10.039242] dhcpcd[585]: eth0: adding route to fec0::/64874machine # [ 10.040544] dhcpcd[585]: eth0: adding default route via fe80::2875machine # [ 10.202629] postgresql-pre-start[634]: performing post-bootstrap initialization ... ok876machine # [ 10.333928] postgresql-pre-start[634]: syncing data to disk ... ok877machine # [ 10.335414] postgresql-pre-start[634]: initdb: warning: enabling "trust" authentication for local connections878machine # [ 10.337575] postgresql-pre-start[634]: 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.879machine # [ 10.340871] postgresql-pre-start[634]: Success. You can now start the database server using:880machine # [ 10.342689] postgresql-pre-start[634]: pg_ctl -D /var/lib/postgresql/18 -l logfile start881machine # [ 10.461400] postgres[697]: [697] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit882machine # [ 10.465239] postgres[697]: [697] LOG: listening on IPv4 address "0.0.0.0", port 5432883machine # [ 10.467207] postgres[697]: [697] LOG: listening on IPv6 address "::", port 5432884machine # [ 10.468973] postgres[697]: [697] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"885machine # [ 10.476728] postgres[706]: [706] LOG: database system was shut down at 2026-11-12 11:49:56 GMT886machine # [ 10.483058] postgres[697]: [697] LOG: database system is ready to accept connections887machine # [ 10.486367] systemd[1]: Started PostgreSQL Server.888machine # [ 10.492621] systemd[1]: Starting PostgreSQL Setup Scripts...889machine # [ 10.739026] postgresql-setup-start[717]: CREATE DATABASE890machine # [ 10.783835] postgresql-setup-start[722]: CREATE ROLE891machine # [ 10.806300] postgresql-setup-start[724]: ALTER DATABASE892machine # [ 10.813057] systemd[1]: Finished PostgreSQL Setup Scripts.893machine # [ 10.814488] systemd[1]: Reached target PostgreSQL.894machine # [ 14.874984] dhcpcd[585]: eth0: leased 10.0.2.15 for 86400 seconds895machine # [ 14.875201] dhcpcd[585]: eth0: adding route to 10.0.2.0/24896machine # [ 14.875271] dhcpcd[585]: eth0: adding default route via 10.0.2.2897machine # [ 14.997859] systemd[1]: Started DHCP Client.898machine # [ 14.999604] systemd[1]: Reached target Network is Online.899machine # [ 15.003483] systemd[1]: Starting k3s service...900machine # [ 15.119959] k3s[824]: time="2026-11-12T11:50:01Z" level=info msg="Acquiring lock file /var/lib/rancher/k3s/data/.lock"901machine # [ 15.122697] k3s[824]: time="2026-11-12T11:50:01Z" level=info msg="Preparing data dir /var/lib/rancher/k3s/data/b9f7776539d53e1567b480015e2ee0c0a8aa3ac6b7b20aaae82735601aa59b06"902machine # [ 16.909785] rustfs-setup-start[844]: mb s3://niks3903machine # [ 16.919691] systemd[1]: Finished Setup RustFS bucket.904machine # [ 18.024816] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Starting k3s 1.36.5+k3s1 (3dd98cc5)"905machine # [ 18.062035] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdle=20, maxOpen=0, maxLifetime=0s, maxIdleTime=2m0s"906machine # [ 18.066928] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Kine built with sqlite from github.com/mattn/go-sqlite3 version 3.53.3"907machine # [ 18.070146] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Configuring database table schema and indexes, this may take a moment..."908machine # [ 18.073349] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Database tables and indexes are up to date"909machine # [ 18.075513] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Running startup VACUUM to reclaim disk space, this may take a moment..."910machine # [ 18.078423] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Startup VACUUM completed successfully"911machine # [ 18.080577] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Kine available at unix://kine.sock"912machine # [ 18.082656] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"913machine # [ 18.085296] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Datastore connection validated successfully, proceeding with bootstrap data generation"914machine # [ 18.088227] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="generated self-signed CA certificate CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:04.8430437 +0000 UTC notAfter=2036-11-09 10:50:04.8430437 +0000 UTC"915machine # [ 18.092504] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"916machine # [ 18.096823] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"917machine # [ 18.101300] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"918machine # [ 18.105769] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"919machine # [ 18.109871] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"920machine # [ 18.113996] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"921machine # [ 18.117867] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="generated self-signed CA certificate CN=k3s-server-ca@1794484204: notBefore=2026-11-12 10:50:04.865833 +0000 UTC notAfter=2036-11-09 10:50:04.865833 +0000 UTC"922machine # [ 18.121563] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-server-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"923machine # [ 18.124895] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=kube-scheduler signed by CN=k3s-server-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"924machine # [ 18.128079] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=kube-controller-manager signed by CN=k3s-server-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"925machine # [ 18.131273] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="generated self-signed CA certificate CN=k3s-request-header-ca@1794484204: notBefore=2026-11-12 10:50:04.86959884 +0000 UTC notAfter=2036-11-09 10:50:04.86959884 +0000 UTC"926machine # [ 18.134773] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"927machine # [ 18.138016] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="generated self-signed CA certificate CN=etcd-server-ca@1794484204: notBefore=2026-11-12 10:50:04.87078026 +0000 UTC notAfter=2036-11-09 10:50:04.87078026 +0000 UTC"928machine # [ 18.141104] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"929machine # [ 18.143732] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="generated self-signed CA certificate CN=etcd-peer-ca@1794484204: notBefore=2026-11-12 10:50:04.87198444 +0000 UTC notAfter=2036-11-09 10:50:04.87198444 +0000 UTC"930machine # [ 18.146739] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"931machine # [ 18.149415] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"932machine # [ 18.175538] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1794484204: notBefore=2026-11-12 10:50:04 +0000 UTC notAfter=2027-11-12 10:50:04 +0000 UTC"933machine # [ 18.180109] k3s[824]: time="2026-11-12T11:50:04Z" level=warning msg="dynamiclistener [::]:6443: no cached certificate available for preload - deferring certificate load until storage initialization or first client request"934machine # [ 18.188308] k3s[824]: time="2026-11-12T11:50:04Z" level=info msg="Active TLS secret / (ver=) (count 11): map[listener.cattle.io/cn-10.0.2.15:10.0.2.15 listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-__1-f16284:::1 listener.cattle.io/cn-fec0__b71b_1c7b_77f_2c94-991e88:fec0::b71b:1c7b:77f:2c94 listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/cn-machine:machine listener.cattle.io/fingerprint:SHA1=6D2D705051670B2D49B89BC22EA43E133419F340]"935machine # [ 19.505175] k3s[824]: time="2026-11-12T11:50:06Z" level=info msg="Password verified locally for node machine"936machine # [ 19.505539] k3s[824]: time="2026-11-12T11:50:06Z" level=info msg="certificate CN=machine signed by CN=k3s-server-ca@1794484204: notBefore=2026-11-12 10:50:06 +0000 UTC notAfter=2027-11-12 10:50:06 +0000 UTC"937machine # [ 19.905785] k3s[824]: time="2026-11-12T11:50:06Z" level=info msg="certificate CN=system:node:machine,O=system:nodes signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:06 +0000 UTC notAfter=2027-11-12 10:50:06 +0000 UTC"938machine # [ 20.005352] k3s[824]: time="2026-11-12T11:50:06Z" level=info msg="certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:06 +0000 UTC notAfter=2027-11-12 10:50:06 +0000 UTC"939machine # [ 20.122546] k3s[824]: time="2026-11-12T11:50:06Z" level=info msg="certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1794484204: notBefore=2026-11-12 10:50:06 +0000 UTC notAfter=2027-11-12 10:50:06 +0000 UTC"940machine # [ 20.247796] k3s[824]: time="2026-11-12T11:50:07Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:41464: runtime core not ready"941machine # [ 20.394010] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Module overlay was already loaded"942machine # [ 20.455232] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.943machine # [ 20.457974] Bridge firewalling registered944machine # [ 20.459452] k3s[824]: time="2026-11-12T11:50:07Z" level=warning msg="Failed to load kernel module iptable_nat with modprobe"945machine # [ 20.467642] k3s[824]: time="2026-11-12T11:50:07Z" level=warning msg="Failed to load kernel module iptable_filter with modprobe"946machine # [ 20.472143] k3s[824]: time="2026-11-12T11:50:07Z" level=warning msg="Failed to load kernel module nft-expr-counter with modprobe"947machine # [ 20.522486] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400"948machine # [ 20.527315] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600"949machine # [ 20.532777] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Set sysctl 'net/ipv4/conf/all/forwarding' to 1"950machine # [ 20.535000] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 131072"951machine # [ 20.540925] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Creating k3s-cert-monitor event broadcaster"952machine # [ 20.542996] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"953machine # [ 20.548295] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Saving cluster bootstrap data to datastore"954machine # [ 20.550107] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"955machine # [ 20.554597] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Connection to etcd is ready"956machine # [ 20.556211] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="ETCD server is now running"957machine # [ 20.557794] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log"958machine # [ 20.559850] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml"959machine # [ 20.568153] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Handling backend connection request [machine]"960machine # [ 20.569804] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"961machine # [ 20.571524] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"962machine # [ 20.573555] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Running kube-apiserver --advertise-port=6443 --allow-privileged=true --anonymous-auth=false --api-audiences=https://kubernetes.default.svc.cluster.local,k3s --authorization-mode=Node,RBAC --bind-address=127.0.0.1 --cert-dir=/var/lib/rancher/k3s/server/tls/temporary-certs --client-ca-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --egress-selector-config-file=/var/lib/rancher/k3s/server/etc/egress-selector-config.yaml --enable-admission-plugins=NodeRestriction --enable-aggregator-routing=true --enable-bootstrap-token-auth=true --etcd-servers=unix://kine.sock --kubelet-certificate-authority=/var/lib/rancher/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.key --kubelet-preferred-address-types=InternalIP,ExternalIP,Hostname --profiling=false --proxy-client-cert-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/var/lib/rancher/k3s/server/tls/request-header-ca.crt --requestheader-extra-headers-prefix=X-Remote-Extra- --requestheader-group-headers=X-Remote-Group --requestheader-username-headers=X-Remote-User --secure-port=6444 --service-account-issuer=https://kubernetes.default.svc.cluster.local --service-account-key-file=/var/lib/rancher/k3s/server/tls/service.key --service-account-signing-key-file=/var/lib/rancher/k3s/server/tls/service.current.key --service-cluster-ip-range=10.43.0.0/16 --service-node-port-range=30000-32767 --storage-backend=etcd3 --tls-cert-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.crt --tls-cipher-suites=TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305,TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305 --tls-private-key-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.key"963machine # [ 20.599448] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Polling for API server readiness: GET /readyz failed: the server is currently unable to handle the request"964machine # [ 20.601771] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Running kube-scheduler --authentication-kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259 --tls-cert-file=/var/lib/rancher/k3s/server/tls/kube-scheduler/kube-scheduler.crt --tls-private-key-file=/var/lib/rancher/k3s/server/tls/kube-scheduler/kube-scheduler.key"965machine # [ 20.608488] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --bind-address=127.0.0.1 --cluster-cidr=10.42.0.0/16 --cluster-signing-kube-apiserver-client-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.nochain.crt --cluster-signing-kube-apiserver-client-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.nochain.crt --cluster-signing-kubelet-client-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/var/lib/rancher/k3s/server/tls/server-ca.nochain.crt --cluster-signing-kubelet-serving-key-file=/var/lib/rancher/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/var/lib/rancher/k3s/server/tls/server-ca.nochain.crt --cluster-signing-legacy-unknown-key-file=/var/lib/rancher/k3s/server/tls/server-ca.key --configure-cloud-routes=false --controllers=*,tokencleaner,-service,-route,-cloud-node-lifecycle --kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --leader-elect=false --profiling=false --root-ca-file=/var/lib/rancher/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/var/lib/rancher/k3s/server/tls/service.current.key --service-cluster-ip-range=10.43.0.0/16 --tls-cert-file=/var/lib/rancher/k3s/server/tls/kube-controller-manager/kube-controller-manager.crt --tls-private-key-file=/var/lib/rancher/k3s/server/tls/kube-controller-manager/kube-controller-manager.key --use-service-account-credentials=true"966machine # [ 20.628770] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-config=/var/lib/rancher/k3s/server/etc/cloud-config.yaml --cloud-provider=k3s --cluster-cidr=10.42.0.0/16 --configure-cloud-routes=false --controllers=*,-route --kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --leader-elect-resource-name=k3s-cloud-controller-manager --node-status-update-frequency=1m0s --profiling=false"967machine # [ 20.637053] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Server node token is available at /var/lib/rancher/k3s/server/token"968machine # [ 20.638702] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="To join server node to cluster: k3s server -s https://10.0.2.15:6443 -t ${SERVER_NODE_TOKEN}"969machine # [ 20.640655] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Agent node token is available at /var/lib/rancher/k3s/server/agent-token"970machine # [ 20.642332] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="To join agent node to cluster: k3s agent -s https://10.0.2.15:6443 -t ${AGENT_NODE_TOKEN}"971machine # [ 20.644170] k3s[824]: I1112 11:50:07.322097 824 options.go:263] external host was not specified, using 10.0.2.15972machine # [ 20.645580] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"973machine # [ 20.646898] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Run: k3s kubectl"974machine # [ 20.647963] k3s[824]: I1112 11:50:07.334190 824 server.go:158] Version: v1.36.5+k3s1975machine # [ 20.649161] k3s[824]: I1112 11:50:07.334242 824 server.go:160] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""976machine # [ 20.772066] k3s[824]: time="2026-11-12T11:50:07Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:41514: runtime core not ready"977machine # [ 20.855909] k3s[824]: E1112 11:50:07.614965 824 options.go:205] The manifest file is empty, ignoring.978machine # [ 20.858551] k3s[824]: I1112 11:50:07.616928 824 shared_informer.go:381] "Waiting for caches to sync" controller="node_authorizer"979machine # [ 20.872108] k3s[824]: I1112 11:50:07.628391 824 plugins.go:157] Loaded 15 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,PodGroupProtection,RuntimeClass,DefaultIngressClass,PodTopologyLabels,MutatingAdmissionPolicy,MutatingAdmissionWebhook.980machine # [ 20.878905] k3s[824]: I1112 11:50:07.628440 824 plugins.go:160] Loaded 17 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,ClusterTrustBundleAttest,CertificateSubjectRestriction,PodGroupWorkloadExists,NodeDeclaredFeatureValidator,JobValidation,PodResizeValidator,ValidatingAdmissionPolicy,ValidatingAdmissionWebhook,ResourceQuota.981machine # [ 20.887682] k3s[824]: I1112 11:50:07.628927 824 instance.go:240] Using reconciler: lease982machine # [ 20.889161] k3s[824]: I1112 11:50:07.629330 824 shared_informer.go:402] "Waiting for caches to sync"983machine # [ 20.890601] k3s[824]: I1112 11:50:07.629646 824 shared_informer.go:402] "Waiting for caches to sync"984machine # [ 20.894553] k3s[824]: I1112 11:50:07.653118 824 handler.go:304] Adding GroupVersion apiextensions.k8s.io v1 to ResourceManager985machine # [ 20.896467] k3s[824]: W1112 11:50:07.653145 824 genericapiserver.go:798] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.986machine # [ 20.901746] k3s[824]: I1112 11:50:07.660844 824 cidrallocator.go:198] starting ServiceCIDR Allocator Controller987machine # [ 20.914248] k3s[824]: time="2026-11-12T11:50:07Z" level=info msg="Running kube-proxy --cluster-cidr=10.42.0.0/16 --conntrack-max-per-core=0 --conntrack-tcp-timeout-close-wait=0s --conntrack-tcp-timeout-established=0s --healthz-bind-address=127.0.0.1 --hostname-override=machine --kubeconfig=/var/lib/rancher/k3s/agent/kubeproxy.kubeconfig --proxy-mode=iptables"988machine # [ 20.951322] k3s[824]: I1112 11:50:07.710396 824 handler.go:304] Adding GroupVersion v1 to ResourceManager989machine # [ 20.953440] k3s[824]: I1112 11:50:07.712542 824 apis.go:112] API group "internal.apiserver.k8s.io" is not enabled, skipping.990machine # [ 20.989340] k3s[824]: I1112 11:50:07.747472 824 apis.go:112] API group "storagemigration.k8s.io" is not enabled, skipping.991machine # [ 21.045726] k3s[824]: I1112 11:50:07.804717 824 handler.go:304] Adding GroupVersion authentication.k8s.io v1 to ResourceManager992machine # [ 21.052082] k3s[824]: W1112 11:50:07.806714 824 genericapiserver.go:798] Skipping API authentication.k8s.io/v1beta1 because it has no resources.993machine # [ 21.054022] k3s[824]: W1112 11:50:07.806743 824 genericapiserver.go:798] Skipping API authentication.k8s.io/v1alpha1 because it has no resources.994machine # [ 21.055835] k3s[824]: I1112 11:50:07.807828 824 handler.go:304] Adding GroupVersion authorization.k8s.io v1 to ResourceManager995machine # [ 21.057552] k3s[824]: W1112 11:50:07.807849 824 genericapiserver.go:798] Skipping API authorization.k8s.io/v1beta1 because it has no resources.996machine # [ 21.059299] k3s[824]: I1112 11:50:07.810945 824 handler.go:304] Adding GroupVersion autoscaling v2 to ResourceManager997machine # [ 21.068054] k3s[824]: I1112 11:50:07.824755 824 handler.go:304] Adding GroupVersion autoscaling v1 to ResourceManager998machine # [ 21.069757] k3s[824]: I1112 11:50:07.828134 824 handler.go:304] Adding GroupVersion batch v1 to ResourceManager999machine # [ 21.071172] k3s[824]: W1112 11:50:07.828163 824 genericapiserver.go:798] Skipping API batch/v1beta1 because it has no resources.1000machine # [ 21.073913] k3s[824]: I1112 11:50:07.830026 824 handler.go:304] Adding GroupVersion certificates.k8s.io v1 to ResourceManager1001machine # [ 21.075537] k3s[824]: W1112 11:50:07.830047 824 genericapiserver.go:798] Skipping API certificates.k8s.io/v1beta1 because it has no resources.1002machine # [ 21.078877] k3s[824]: W1112 11:50:07.830055 824 genericapiserver.go:798] Skipping API certificates.k8s.io/v1alpha1 because it has no resources.1003machine # [ 21.084200] k3s[824]: I1112 11:50:07.831300 824 handler.go:304] Adding GroupVersion coordination.k8s.io v1 to ResourceManager1004machine # [ 21.085777] k3s[824]: W1112 11:50:07.831319 824 genericapiserver.go:798] Skipping API coordination.k8s.io/v1beta1 because it has no resources.1005machine # [ 21.087490] k3s[824]: W1112 11:50:07.831326 824 genericapiserver.go:798] Skipping API coordination.k8s.io/v1alpha2 because it has no resources.1006machine # [ 21.092199] k3s[824]: I1112 11:50:07.833893 824 handler.go:304] Adding GroupVersion discovery.k8s.io v1 to ResourceManager1007machine # [ 21.093823] k3s[824]: W1112 11:50:07.833937 824 genericapiserver.go:798] Skipping API discovery.k8s.io/v1beta1 because it has no resources.1008machine # [ 21.095521] k3s[824]: I1112 11:50:07.849080 824 handler.go:304] Adding GroupVersion networking.k8s.io v1 to ResourceManager1009machine # [ 21.100118] k3s[824]: W1112 11:50:07.849115 824 genericapiserver.go:798] Skipping API networking.k8s.io/v1beta1 because it has no resources.1010machine # [ 21.101862] k3s[824]: I1112 11:50:07.849864 824 handler.go:304] Adding GroupVersion node.k8s.io v1 to ResourceManager1011machine # [ 21.103322] k3s[824]: W1112 11:50:07.849878 824 genericapiserver.go:798] Skipping API node.k8s.io/v1beta1 because it has no resources.1012machine # [ 21.105051] k3s[824]: W1112 11:50:07.849884 824 genericapiserver.go:798] Skipping API node.k8s.io/v1alpha1 because it has no resources.1013machine # [ 21.106709] k3s[824]: I1112 11:50:07.851094 824 handler.go:304] Adding GroupVersion policy v1 to ResourceManager1014machine # [ 21.108100] k3s[824]: W1112 11:50:07.851110 824 genericapiserver.go:798] Skipping API policy/v1beta1 because it has no resources.1015machine # [ 21.109735] k3s[824]: I1112 11:50:07.859061 824 handler.go:304] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager1016machine # [ 21.111302] k3s[824]: W1112 11:50:07.859094 824 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.1017machine # [ 21.113163] k3s[824]: W1112 11:50:07.859103 824 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.1018machine # [ 21.114914] k3s[824]: I1112 11:50:07.866610 824 handler.go:304] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager1019machine # [ 21.116429] k3s[824]: W1112 11:50:07.866646 824 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.1020machine # [ 21.118128] k3s[824]: W1112 11:50:07.866656 824 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1alpha2 because it has no resources.1021machine # [ 21.119842] k3s[824]: I1112 11:50:07.870818 824 handler.go:304] Adding GroupVersion storage.k8s.io v1 to ResourceManager1022machine # [ 21.122585] k3s[824]: W1112 11:50:07.870865 824 genericapiserver.go:798] Skipping API storage.k8s.io/v1beta1 because it has no resources.1023machine # [ 21.124461] k3s[824]: W1112 11:50:07.870875 824 genericapiserver.go:798] Skipping API storage.k8s.io/v1alpha1 because it has no resources.1024machine # [ 21.127055] k3s[824]: I1112 11:50:07.876328 824 handler.go:304] Adding GroupVersion flowcontrol.apiserver.k8s.io v1 to ResourceManager1025machine # [ 21.128742] k3s[824]: W1112 11:50:07.876364 824 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta3 because it has no resources.1026machine # [ 21.130554] k3s[824]: W1112 11:50:07.876374 824 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta2 because it has no resources.1027machine # [ 21.132444] k3s[824]: W1112 11:50:07.876380 824 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta1 because it has no resources.1028machine # [ 21.136166] k3s[824]: I1112 11:50:07.881763 824 handler.go:304] Adding GroupVersion apps v1 to ResourceManager1029machine # [ 21.137657] k3s[824]: W1112 11:50:07.881828 824 genericapiserver.go:798] Skipping API apps/v1beta2 because it has no resources.1030machine # [ 21.139221] k3s[824]: W1112 11:50:07.881838 824 genericapiserver.go:798] Skipping API apps/v1beta1 because it has no resources.1031machine # [ 21.141674] k3s[824]: I1112 11:50:07.886303 824 handler.go:304] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager1032machine # [ 21.143358] k3s[824]: W1112 11:50:07.886327 824 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.1033machine # [ 21.145391] k3s[824]: W1112 11:50:07.886334 824 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources.1034machine # [ 21.147232] k3s[824]: I1112 11:50:07.886909 824 handler.go:304] Adding GroupVersion events.k8s.io v1 to ResourceManager1035machine # [ 21.148773] k3s[824]: W1112 11:50:07.886921 824 genericapiserver.go:798] Skipping API events.k8s.io/v1beta1 because it has no resources.1036machine # [ 21.150493] k3s[824]: I1112 11:50:07.890185 824 handler.go:304] Adding GroupVersion resource.k8s.io v1 to ResourceManager1037machine # [ 21.151994] k3s[824]: W1112 11:50:07.890209 824 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta2 because it has no resources.1038machine # [ 21.153694] k3s[824]: W1112 11:50:07.890217 824 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta1 because it has no resources.1039machine # [ 21.155384] k3s[824]: W1112 11:50:07.890223 824 genericapiserver.go:798] Skipping API resource.k8s.io/v1alpha3 because it has no resources.1040machine # [ 21.157205] k3s[824]: I1112 11:50:07.893399 824 handler.go:304] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager1041machine # [ 21.159039] k3s[824]: W1112 11:50:07.893431 824 genericapiserver.go:798] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.1042machine # [ 21.546529] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="containerd is now running"1043machine # [ 21.558043] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/awya228ix9q04gd4v7aikhb88qm6mx2q-niks3-server.tar"1044machine # [ 21.745527] k3s[824]: I1112 11:50:08.504135 824 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1045machine # [ 21.748094] k3s[824]: I1112 11:50:08.504572 824 secure_serving.go:214] Serving securely on 127.0.0.1:64441046machine # [ 21.752135] k3s[824]: I1112 11:50:08.504624 824 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1047machine # [ 21.754261] k3s[824]: I1112 11:50:08.510789 824 dynamic_serving_content.go:135] "Starting controller" name="aggregator-proxy-cert::/var/lib/rancher/k3s/server/tls/client-auth-proxy.crt::/var/lib/rancher/k3s/server/tls/client-auth-proxy.key"1048machine # [ 21.757156] k3s[824]: I1112 11:50:08.510918 824 local_available_controller.go:156] Starting LocalAvailability controller1049machine # [ 21.758647] k3s[824]: I1112 11:50:08.510933 824 cache.go:32] Waiting for caches to sync for LocalAvailability controller1050machine # [ 21.764160] k3s[824]: I1112 11:50:08.510959 824 controller.go:87] "Starting OpenAPI AggregationController"1051machine # [ 21.765609] k3s[824]: I1112 11:50:08.511202 824 cluster_authentication_trust_controller.go:459] Starting cluster_authentication_trust_controller controller1052machine # [ 21.767486] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Waiting for caches to sync" logger=k3s1053machine # [ 21.768841] k3s[824]: I1112 11:50:08.511253 824 apf_controller.go:377] Starting API Priority and Fairness config controller1054machine # [ 21.770393] k3s[824]: I1112 11:50:08.511282 824 aggregator.go:185] waiting for initial CRD sync...1055machine # [ 21.771615] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Starting legacy_token_tracking_controller" logger=k3s1056machine # [ 21.773149] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Waiting for caches to sync" logger=k3s1057machine # [ 21.774414] k3s[824]: I1112 11:50:08.512772 824 customresource_discovery_controller.go:294] Starting DiscoveryController1058machine # [ 21.775899] k3s[824]: I1112 11:50:08.512932 824 storage_readiness_hook.go:70] Storage is ready for all registered resources1059machine # [ 21.779956] k3s[824]: I1112 11:50:08.512958 824 remote_available_controller.go:434] Starting RemoteAvailability controller1060machine # [ 21.781678] k3s[824]: I1112 11:50:08.512968 824 cache.go:32] Waiting for caches to sync for RemoteAvailability controller1061machine # [ 21.783185] k3s[824]: I1112 11:50:08.512995 824 controller.go:89] "Starting OpenAPI V3 AggregationController"1062machine # [ 21.785696] k3s[824]: I1112 11:50:08.504811 824 tlsconfig.go:243] "Starting DynamicServingCertificateController"1063machine # [ 21.787188] k3s[824]: I1112 11:50:08.513493 824 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1064machine # [ 21.789470] k3s[824]: I1112 11:50:08.513571 824 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1065machine # [ 21.791607] k3s[824]: I1112 11:50:08.513920 824 crdregistration_controller.go:114] Starting crd-autoregister controller1066machine # [ 21.795926] k3s[824]: I1112 11:50:08.513934 824 shared_informer.go:381] "Waiting for caches to sync" controller="crd-autoregister"1067machine # [ 21.799079] k3s[824]: I1112 11:50:08.514003 824 repairip.go:210] Starting ipallocator-repair-controller1068machine # [ 21.801683] k3s[824]: I1112 11:50:08.514011 824 shared_informer.go:381] "Waiting for caches to sync" controller="ipallocator-repair-controller"1069machine # [ 21.803444] k3s[824]: I1112 11:50:08.514613 824 controller.go:142] Starting OpenAPI controller1070machine # [ 21.806880] k3s[824]: I1112 11:50:08.514644 824 controller.go:90] Starting OpenAPI V3 controller1071machine # [ 21.809541] k3s[824]: I1112 11:50:08.514662 824 naming_controller.go:305] Starting NamingConditionController1072machine # [ 21.811953] k3s[824]: I1112 11:50:08.514715 824 nonstructuralschema_controller.go:202] Starting NonStructuralSchemaConditionController1073machine # [ 21.815415] k3s[824]: I1112 11:50:08.514735 824 apiapproval_controller.go:196] Starting KubernetesAPIApprovalPolicyConformantConditionController1074machine # [ 21.819002] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Starting CRDFinalizer" logger=k3s1075machine # [ 21.821549] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Starting apiserver lease garbage collector" logger=k3s1076machine # [ 21.827646] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Waiting for caches to sync" logger=k3s1077machine # [ 21.829074] k3s[824]: I1112 11:50:08.520091 824 system_namespaces_controller.go:66] Starting system namespaces controller1078machine # [ 21.830660] k3s[824]: I1112 11:50:08.520120 824 controller.go:113] "Deleting old lease on startup" lease="kube-system/apiserver-ik4pcwfs7qgdl76byc4pomgvia"1079machine # [ 21.832853] k3s[824]: I1112 11:50:08.520303 824 apiservice_controller.go:100] Starting APIServiceRegistrationController1080machine # [ 21.835828] k3s[824]: I1112 11:50:08.520315 824 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller1081machine # [ 21.839286] k3s[824]: I1112 11:50:08.504764 824 dynamic_serving_content.go:135] "Starting controller" name="serving-cert::/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.crt::/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.key"1082machine # [ 21.842420] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg=Starting controller=kubernetes-service-cidr-controller logger=k3s1083machine # [ 21.844050] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Waiting for caches to sync" logger=k3s1084machine # [ 21.852163] k3s[824]: I1112 11:50:08.611203 824 cache.go:39] Caches are synced for LocalAvailability controller1085machine # [ 21.856200] k3s[824]: I1112 11:50:08.611288 824 apf_controller.go:382] Running API Priority and Fairness config worker1086machine # [ 21.857778] k3s[824]: I1112 11:50:08.611298 824 apf_controller.go:385] Running API Priority and Fairness periodic rebalancing process1087machine # [ 21.859439] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Caches are synced" logger=k3s1088machine # [ 21.861253] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Caches are synced" logger=k3s1089machine # [ 21.862524] k3s[824]: I1112 11:50:08.613039 824 cache.go:39] Caches are synced for RemoteAvailability controller1090machine # [ 21.863913] k3s[824]: I1112 11:50:08.614565 824 shared_informer.go:388] "Caches are synced" controller="ipallocator-repair-controller"1091machine # [ 21.865728] k3s[824]: I1112 11:50:08.614610 824 shared_informer.go:388] "Caches are synced" controller="crd-autoregister"1092machine # [ 21.867212] k3s[824]: I1112 11:50:08.614698 824 aggregator.go:187] initial CRD sync complete...1093machine # [ 21.868545] k3s[824]: I1112 11:50:08.614711 824 autoregister_controller.go:144] Starting autoregister controller1094machine # [ 21.870128] k3s[824]: I1112 11:50:08.614722 824 cache.go:32] Waiting for caches to sync for autoregister controller1095machine # [ 21.871799] k3s[824]: I1112 11:50:08.614730 824 cache.go:39] Caches are synced for autoregister controller1096machine # [ 21.873290] k3s[824]: I1112 11:50:08.617063 824 shared_informer.go:388] "Caches are synced" controller="node_authorizer"1097machine # [ 21.874879] k3s[824]: I1112 11:50:08.620354 824 cache.go:39] Caches are synced for APIServiceRegistrationController controller1098machine # [ 21.876479] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Caches are synced" logger=k3s1099machine # [ 21.877646] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Caches are synced" logger=k3s1100machine # [ 21.878802] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Creating default ServiceCIDR" CIDRs="[10.43.0.0/16]" logger=k3s1101machine # [ 21.880365] k3s[824]: I1112 11:50:08.620938 824 handler_discovery.go:459] Starting ResourceDiscoveryManager1102machine # [ 21.881701] k3s[824]: I1112 11:50:08.629807 824 shared_informer.go:409] "Caches are synced"1103machine # [ 21.882856] k3s[824]: I1112 11:50:08.629844 824 policy_source.go:248] refreshing policies1104machine # [ 21.883998] k3s[824]: I1112 11:50:08.629943 824 shared_informer.go:409] "Caches are synced"1105machine # [ 21.885200] k3s[824]: I1112 11:50:08.629954 824 policy_source.go:248] refreshing policies1106machine # [ 21.895546] k3s[824]: E1112 11:50:08.654533 824 controller.go:201] "Failed to ensure lease exists, will retry" err="namespaces \"kube-system\" not found" interval="200ms"1107machine # [ 21.908773] k3s[824]: time="2026-11-12T11:50:08Z" level=error msg="Error while syncing ConfigMap" configmap=kube-system/kube-apiserver-legacy-service-account-token-tracking error="namespaces \"kube-system\" not found" logger=k3s/UnhandledError1108machine # [ 21.912384] k3s[824]: E1112 11:50:08.667852 824 controller.go:95] Unable to perform initial Kubernetes service initialization: namespaces "default" not found1109machine # [ 21.977127] k3s[824]: I1112 11:50:08.735610 824 cidrallocator.go:302] created ClusterIP allocator for Service CIDR 10.43.0.0/161110machine # [ 21.978877] k3s[824]: time="2026-11-12T11:50:08Z" level=info msg="Setting default ServiceCIDR condition Ready to True" logger=k3s1111machine # [ 21.991153] k3s[824]: I1112 11:50:08.750242 824 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161112machine # [ 22.107979] k3s[824]: I1112 11:50:08.866965 824 controller.go:667] quota admission added evaluator for: leases.coordination.k8s.io1113machine # [ 22.439230] k3s[824]: time="2026-11-12T11:50:09Z" level=info msg="Imported docker.io/library/niks3-server:1.17.1-aarch64-linux"1114machine # [ 22.442051] k3s[824]: time="2026-11-12T11:50:09Z" level=info msg="Tagged docker.io/library/niks3-server@sha256:608fcbe11df6372e85e203fcd91744b7d046d3968d16afe360205ef96dc065f7"1115machine # [ 22.461325] k3s[824]: time="2026-11-12T11:50:09Z" level=info msg="Imported 1 images from /var/lib/rancher/k3s/agent/images/nixos/awya228ix9q04gd4v7aikhb88qm6mx2q-niks3-server.tar in 903.84ms"1116machine # [ 22.463933] k3s[824]: time="2026-11-12T11:50:09Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/kyix6dphrkrxwz27rcspc3n86sqsafq8-k3s-airgap-images-arm64.tar.zst"1117machine # [ 22.541708] k3s[824]: time="2026-11-12T11:50:09Z" level=info msg="Polling for API server readiness: GET /readyz failed: unknown"1118machine # [ 22.560465] k3s[824]: time="2026-11-12T11:50:09Z" level=info msg="Running kubelet --cloud-provider=external --config-dir=/var/lib/rancher/k3s/agent/etc/kubelet.conf.d --containerd=/run/k3s/containerd/containerd.sock --hostname-override=machine --kubeconfig=/var/lib/rancher/k3s/agent/kubelet.kubeconfig --node-ip=10.0.2.15,fec0::b71b:1c7b:77f:2c94 --node-labels= --read-only-port=0"1119machine # [ 22.768487] k3s[824]: I1112 11:50:09.527530 824 storage_scheduling.go:137] created PriorityClass system-node-critical with value 20000010001120machine # [ 22.777788] k3s[824]: I1112 11:50:09.536861 824 storage_scheduling.go:137] created PriorityClass system-cluster-critical with value 20000000001121machine # [ 22.779651] k3s[824]: I1112 11:50:09.536895 824 storage_scheduling.go:153] all system priority classes are created successfully or already exist.1122machine # [ 23.257120] k3s[824]: I1112 11:50:10.016158 824 controller.go:667] quota admission added evaluator for: roles.rbac.authorization.k8s.io1123machine # [ 23.304096] k3s[824]: I1112 11:50:10.061157 824 controller.go:667] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io1124machine # [ 23.419885] k3s[824]: I1112 11:50:10.178896 824 alloc.go:329] "allocated clusterIPs" service="default/kubernetes" clusterIPs={"IPv4":"10.43.0.1"}1125machine # [ 23.432097] k3s[824]: W1112 11:50:10.189954 824 lease.go:265] Resetting endpoints for master service "kubernetes" to [10.0.2.15]1126machine # [ 23.433892] k3s[824]: I1112 11:50:10.191150 824 controller.go:667] quota admission added evaluator for: endpoints1127machine # [ 23.440069] k3s[824]: I1112 11:50:10.198991 824 controller.go:667] quota admission added evaluator for: endpointslices.discovery.k8s.io1128machine # [ 24.533632] k3s[824]: Flag --containerd has been deprecated, This is a cadvisor flag that was mistakenly registered with the Kubelet. Due to legacy concerns, it will follow the standard CLI deprecation timeline before being removed.1129machine # [ 24.551893] k3s[824]: I1112 11:50:11.310968 824 server.go:541] "Kubelet version" kubeletVersion="v1.36.5+k3s1"1130machine # [ 24.555888] k3s[824]: I1112 11:50:11.312631 824 server.go:543] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1131machine # [ 24.560406] k3s[824]: I1112 11:50:11.312694 824 watchdog_linux.go:94] "Systemd watchdog is not enabled"1132machine # [ 24.563936] k3s[824]: I1112 11:50:11.312706 824 watchdog_linux.go:137] "Systemd watchdog is not enabled or the interval is invalid, so health checking will not be started."1133machine # [ 24.571092] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Waiting for untainted node"1134machine # [ 24.576253] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Creating k3s-supervisor event broadcaster"1135machine # [ 24.577591] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Kube API server is now running"1136machine # [ 24.578765] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="k3s is up and running"1137machine # [ 24.582797] systemd[1]: Started k3s service.1138machine # [ 24.583911] systemd[1]: Reached target Multi-User System.1139machine # [ 24.588632] systemd[1]: Startup finished in 825ms (kernel) + 3.625s (initrd) + 20.111s (userspace) = 24.563s.1140machine # [ 24.618532] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Event occurred" apiVersion= fieldPath= kind=Node logger=k3s message="Node and Certificate Authority certificates managed by k3s are OK" object=machine reason=CertificateExpirationOK type=Normal1141machine # [ 24.627238] k3s[824]: I1112 11:50:11.386322 824 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt"1142[25.37s] machine: (finished: waiting for unit k3s.service, in 25.36 seconds)1143[25.37s] machine: waiting for unit rustfs-setup.service1144machine # [ 24.661484] k3s[824]: E1112 11:50:11.420579 824 options.go:205] The manifest file is empty, ignoring.1145machine # [ 24.671788] k3s[824]: I1112 11:50:11.430083 824 controllermanager.go:204] "Starting" version="v1.36.5+k3s1"1146machine # [ 24.673457] k3s[824]: I1112 11:50:11.430130 824 controllermanager.go:206] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1147machine # [ 24.698133] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Creating embedded CRD addons.k3s.cattle.io"1148machine # [ 24.701240] k3s[824]: I1112 11:50:11.460340 824 secure_serving.go:214] Serving securely on 127.0.0.1:102571149machine # [ 24.704789] k3s[824]: I1112 11:50:11.462653 824 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1150machine # [ 24.708186] k3s[824]: I1112 11:50:11.462687 824 shared_informer.go:402] "Waiting for caches to sync"1151machine # [ 24.709568] k3s[824]: I1112 11:50:11.462721 824 dynamic_serving_content.go:135] "Starting controller" name="serving-cert::/var/lib/rancher/k3s/server/tls/kube-controller-manager/kube-controller-manager.crt::/var/lib/rancher/k3s/server/tls/kube-controller-manager/kube-controller-manager.key"1152machine # [ 24.716693] k3s[824]: I1112 11:50:11.462845 824 tlsconfig.go:243] "Starting DynamicServingCertificateController"1153machine # [ 24.718275] k3s[824]: I1112 11:50:11.462932 824 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1154machine # [ 24.720834] k3s[824]: I1112 11:50:11.462948 824 shared_informer.go:402] "Waiting for caches to sync"1155machine # [ 24.722303] k3s[824]: I1112 11:50:11.462965 824 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1156machine # [ 24.724930] k3s[824]: I1112 11:50:11.462980 824 shared_informer.go:402] "Waiting for caches to sync"1157machine # [ 24.732118] k3s[824]: I1112 11:50:11.488061 824 server.go:1444] "Using cgroup driver setting received from the CRI runtime" cgroupDriver="systemd"1158machine # [ 24.734351] k3s[824]: I1112 11:50:11.493453 824 server.go:804] "--cgroups-per-qos enabled, but --cgroup-root was not specified. Defaulting to /"1159machine # [ 24.736415] k3s[824]: I1112 11:50:11.493547 824 server.go:865] "NoSwap is set due to memorySwapBehavior not specified" memorySwapBehavior="" FailSwapOn=false1160machine # [ 24.738999] k3s[824]: I1112 11:50:11.493877 824 container_manager_linux.go:273] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]1161machine # [ 24.741213] k3s[824]: I1112 11:50:11.493911 824 container_manager_linux.go:278] "Creating Container Manager object based on Node Config" nodeConfig={"NodeName":"machine","RuntimeCgroupsName":"","SystemCgroupsName":"","KubeletCgroupsName":"","KubeletOOMScoreAdj":-999,"ContainerRuntime":"","CgroupsPerQOS":true,"CgroupRoot":"/","CgroupDriver":"systemd","KubeletRootDir":"/var/lib/kubelet","ProtectKernelDefaults":false,"KubeReservedCgroupName":"","SystemReservedCgroupName":"","ReservedSystemCPUs":{},"EnforceNodeAllocatable":{"pods":{}},"KubeReserved":null,"SystemReserved":null,"HardEvictionThresholds":[{"Signal":"nodefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"Signal":"imagefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null}],"QOSReserved":{},"CPUManagerPolicy":"none","CPUManagerPolicyOptions":null,"TopologyManagerScope":"container","CPUManagerReconcilePeriod":10000000000,"MemoryManagerPolicy":"None","MemoryManagerReservedMemory":null,"MemoryReservationPolicy":"None","PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null,"CgroupVersion":2}1162machine # [ 24.756433] k3s[824]: I1112 11:50:11.494203 824 topology_manager.go:172] "Creating topology manager with none policy"1163machine # [ 24.758743] k3s[824]: I1112 11:50:11.494220 824 container_manager_linux.go:309] "Creating device plugin manager"1164machine # [ 24.760649] k3s[824]: I1112 11:50:11.494325 824 container_manager_linux.go:318] "Creating Dynamic Resource Allocation (DRA) manager"1165machine # [ 24.762923] k3s[824]: I1112 11:50:11.497718 824 state_mem.go:45] "Initialized" logger="CPUManager state memory"1166machine # [ 24.764596] k3s[824]: I1112 11:50:11.497993 824 kubelet.go:485] "Attempting to sync node with API server"1167machine # [ 24.769491] k3s[824]: I1112 11:50:11.498015 824 kubelet.go:386] "Adding static pod path" path="/var/lib/rancher/k3s/agent/pod-manifests"1168machine # [ 24.771285] k3s[824]: I1112 11:50:11.498046 824 kubelet.go:397] "Adding apiserver pod source"1169machine # [ 24.772621] k3s[824]: I1112 11:50:11.499212 824 apiserver.go:41] "Waiting for node sync before watching apiserver pods"1170machine # [ 24.774159] k3s[824]: I1112 11:50:11.520953 824 kuberuntime_manager.go:308] "Container runtime initialized" containerRuntime="containerd" version="2.3.4-k3s1.36" apiVersion="v1"1171[25.49s] machine: (finished: waiting for unit rustfs-setup.service, in 0.12 seconds)1172[25.49s] machine: waiting for unit postgresql.service1173machine # [ 24.782709] k3s[824]: I1112 11:50:11.541769 824 kubelet.go:1002] "Not starting ClusterTrustBundle informer because we are in static kubelet mode or the ClusterTrustBundleProjection featuregate is disabled"1174machine # [ 24.787119] k3s[824]: I1112 11:50:11.546143 824 kubelet.go:1029] "Not starting PodCertificateRequest manager because we are in static kubelet mode or the PodCertificateProjection feature gate is disabled"1175machine # [ 24.790378] k3s[824]: W1112 11:50:11.546545 824 probe.go:275] Flexvolume plugin directory at /usr/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating.1176machine # [ 24.792837] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Creating embedded CRD etcdsnapshotfiles.k3s.cattle.io"1177machine # [ 24.811169] k3s[824]: I1112 11:50:11.570258 824 shared_informer.go:409] "Caches are synced"1178machine # [ 24.812731] k3s[824]: I1112 11:50:11.570706 824 shared_informer.go:409] "Caches are synced"1179machine # [ 24.814058] k3s[824]: I1112 11:50:11.570803 824 shared_informer.go:409] "Caches are synced"1180[25.54s] machine: (finished: waiting for unit postgresql.service, in 0.05 seconds)1181[25.54s] subtest: chart deploys and becomes ready1182??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1183 File "/nix/store/81dgbf2d9k9llajgi9597ahypdjn5iam-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391184[25.54s] machine: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s1185??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1186 File "/nix/store/81dgbf2d9k9llajgi9597ahypdjn5iam-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391187machine # [ 24.843188] k3s[824]: I1112 11:50:11.602097 824 shared_informer.go:402] "Waiting for caches to sync"1188machine # [ 24.845729] k3s[824]: I1112 11:50:11.603950 824 server.go:1280] "Started kubelet"1189machine # [ 24.851129] k3s[824]: I1112 11:50:11.609963 824 fs_resource_analyzer.go:69] "Starting FS ResourceAnalyzer"1190machine # [ 24.856524] k3s[824]: I1112 11:50:11.615589 824 server.go:193] "Starting to listen" address="0.0.0.0" port=102501191machine # [ 24.859121] k3s[824]: I1112 11:50:11.618233 824 server.go:354] "Adding debug handlers to kubelet server"1192machine # [ 24.862187] k3s[824]: I1112 11:50:11.621271 824 ratelimit.go:56] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=101193machine # [ 24.868166] k3s[824]: I1112 11:50:11.623267 824 server_v1.go:49] "podresources" method="list" useActivePods=true1194machine # [ 24.869723] k3s[824]: I1112 11:50:11.623469 824 server.go:264] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock"1195machine # [ 24.871775] k3s[824]: I1112 11:50:11.624129 824 dynamic_serving_content.go:135] "Starting controller" name="kubelet-server-cert-files::/var/lib/rancher/k3s/agent/serving-kubelet.crt::/var/lib/rancher/k3s/agent/serving-kubelet.key"1196machine # [ 24.877595] k3s[824]: I1112 11:50:11.624240 824 tlsconfig.go:243] "Starting DynamicServingCertificateController"1197machine # [ 24.879338] k3s[824]: I1112 11:50:11.638450 824 volume_manager.go:310] "Starting Kubelet Volume Manager"1198machine # [ 24.886715] k3s[824]: E1112 11:50:11.643706 824 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1199machine # [ 24.888767] k3s[824]: E1112 11:50:11.643996 824 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1200machine # [ 24.901855] k3s[824]: I1112 11:50:11.660695 824 desired_state_of_world_populator.go:146] "Desired state populator starts to run"1201machine # [ 24.903551] k3s[824]: I1112 11:50:11.660841 824 reconciler.go:29] "Reconciler: start to sync state"1202machine # [ 24.905531] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Creating embedded CRD helmchartconfigs.helm.cattle.io"1203machine # [ 24.920543] k3s[824]: I1112 11:50:11.679628 824 factory.go:222] Registration of the systemd container factory successfully1204machine # [ 24.923785] k3s[824]: I1112 11:50:11.681765 824 factory.go:220] Registration of the crio container factory failed: Get "http://%2Fvar%2Frun%2Fcrio%2Fcrio.sock/info": dial unix /var/run/crio/crio.sock: connect: no such file or directory1205machine # [ 24.949907] k3s[824]: I1112 11:50:11.709005 824 factory.go:222] Registration of the containerd container factory successfully1206machine # [ 24.958940] k3s[824]: E1112 11:50:11.718039 824 kubelet.go:1725] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"1207machine # [ 24.979223] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Creating embedded CRD helmcharts.helm.cattle.io"1208machine # [ 24.996881] k3s[824]: E1112 11:50:11.752592 824 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1209machine # [ 24.999203] k3s[824]: E1112 11:50:11.752640 824 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1210machine # [ 25.006494] k3s[824]: I1112 11:50:11.764173 824 controller.go:667] quota admission added evaluator for: serviceaccounts1211machine # [ 25.014937] k3s[824]: I1112 11:50:11.773879 824 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1212machine # [ 25.072142] k3s[824]: E1112 11:50:11.831120 824 nodelease.go:50] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"machine\" not found" node="machine"1213machine # [ 25.085759] k3s[824]: I1112 11:50:11.843895 824 cpu_manager.go:235] "Starting" policy="none"1214machine # [ 25.087072] k3s[824]: I1112 11:50:11.843917 824 cpu_manager.go:236] "Reconciling" reconcilePeriod="10s"1215machine # [ 25.090895] k3s[824]: I1112 11:50:11.843949 824 state_mem.go:45] "Initialized" logger="CPUManager state checkpoint.CPUManager state memory"1216machine # [ 25.094331] k3s[824]: E1112 11:50:11.844401 824 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1217machine # [ 25.100215] k3s[824]: E1112 11:50:11.855889 824 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1218machine # [ 25.103400] k3s[824]: I1112 11:50:11.861451 824 policy_none.go:50] "Start"1219machine # [ 25.113230] k3s[824]: I1112 11:50:11.872244 824 memory_manager.go:190] "Starting memorymanager" policy="None"1220machine # [ 25.117101] k3s[824]: I1112 11:50:11.872289 824 state_mem.go:40] "Initializing new in-memory state store" logger="Memory Manager state checkpoint"1221machine # [ 25.120532] k3s[824]: I1112 11:50:11.864890 824 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1222machine # [ 25.128052] k3s[824]: I1112 11:50:11.883614 824 policy_none.go:44] "Start"1223machine # [ 25.170773] systemd[1]: Created slice libcontainer container kubepods.slice.1224machine # [ 25.186742] k3s[824]: E1112 11:50:11.945692 824 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1225machine # [ 25.200363] k3s[824]: E1112 11:50:11.959432 824 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1226machine # [ 25.208371] k3s[824]: I1112 11:50:11.967406 824 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv4"1227machine # [ 25.218765] systemd[1]: Created slice libcontainer container kubepods-burstable.slice.1228machine # [ 25.221845] k3s[824]: I1112 11:50:11.978255 824 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv6"1229machine # [ 25.223404] k3s[824]: I1112 11:50:11.978288 824 status_manager.go:277] "Starting to sync pod status with apiserver"1230machine # [ 25.225537] k3s[824]: I1112 11:50:11.978327 824 kubelet.go:2622] "Starting kubelet main sync loop"1231machine # [ 25.227186] k3s[824]: E1112 11:50:11.978373 824 kubelet.go:2646] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"1232machine # [ 25.234209] k3s[824]: I1112 11:50:11.993192 824 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1233machine # [ 25.238120] k3s[824]: time="2026-11-12T11:50:11Z" level=info msg="Waiting for CRD helmcharts.helm.cattle.io to become available"1234machine # [ 25.250177] systemd[1]: Created slice libcontainer container kubepods-besteffort.slice.1235machine # [ 25.253483] k3s[824]: I1112 11:50:12.012575 824 shared_informer.go:409] "Caches are synced"1236machine # Error from server (NotFound): namespaces "niks3" not found1237machine # [ 25.281818] k3s[824]: I1112 11:50:12.040895 824 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1238machine # [ 25.287688] k3s[824]: E1112 11:50:12.046695 824 manager.go:525] "Failed to read data from checkpoint" err="checkpoint is not found" checkpoint="kubelet_internal_checkpoint"1239machine # [ 25.296266] k3s[824]: I1112 11:50:12.046896 824 eviction_manager.go:194] "Eviction manager: starting control loop"1240machine # [ 25.297763] k3s[824]: I1112 11:50:12.046927 824 container_log_manager.go:146] "Initializing container log rotate workers" workers=1 monitorPeriod="10s"1241machine # [ 25.299593] k3s[824]: I1112 11:50:12.047811 824 plugin_manager.go:121] "Starting Kubelet Plugin Manager"1242machine # [ 25.305529] k3s[824]: E1112 11:50:12.051063 824 eviction_manager.go:272] "eviction manager: failed to check if we have separate container filesystem. Ignoring." err="no imagefs label for configured runtime"1243machine # [ 25.308300] k3s[824]: E1112 11:50:12.051129 824 eviction_manager.go:297] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"machine\" not found"1244machine # [ 25.313708] k3s[824]: E1112 11:50:12.072097 824 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1245machine # [ 25.315909] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Done waiting for CRD helmcharts.helm.cattle.io to become available"1246machine # [ 25.320121] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-40.1.5+up40.1.0.tgz"1247machine # [ 25.322082] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-40.1.5+up40.1.0.tgz"1248machine # [ 25.323991] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml"1249machine # [ 25.326818] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml"1250machine # [ 25.332212] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml"1251machine # [ 25.334007] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml"1252machine # [ 25.335673] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/runtimes.yaml"1253machine # [ 25.337425] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml"1254machine # [ 25.339146] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Starting dynamiclistener CN filter node controller with SANs: [127.0.0.1 ::1 localhost machine 10.0.2.15 fec0::b71b:1c7b:77f:2c94 10.43.0.1 kubernetes kubernetes.default kubernetes.default.svc kubernetes.default.svc.cluster.local]"1255machine # [ 25.342805] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tunnel server egress proxy mode: agent"1256machine # [ 25.372083] k3s[824]: I1112 11:50:12.130567 824 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podcertificaterequest-cleaner-controller" requiredFeatureGates=["PodCertificateRequest"]1257machine # [ 25.374935] k3s[824]: I1112 11:50:12.130630 824 controllermanager.go:641] "Warning: skipping controller" controller="podcertificaterequest-cleaner-controller"1258machine # [ 25.379942] k3s[824]: I1112 11:50:12.130641 824 controllermanager.go:689] "Warning: controller is disabled" controller="node-route-controller"1259machine # [ 25.388098] k3s[824]: E1112 11:50:12.144038 824 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1260machine # [ 25.390728] k3s[824]: I1112 11:50:12.149824 824 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller" requiredFeatureGates=["ClusterTrustBundle"]1261machine # [ 25.393838] k3s[824]: I1112 11:50:12.152955 824 controllermanager.go:641] "Warning: skipping controller" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller"1262machine # [ 25.396449] k3s[824]: I1112 11:50:12.155216 824 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="storageversion-garbage-collector-controller" requiredFeatureGates=["APIServerIdentity","StorageVersionAPI"]1263machine # [ 25.399336] k3s[824]: I1112 11:50:12.155239 824 controllermanager.go:641] "Warning: skipping controller" controller="storageversion-garbage-collector-controller"1264machine # [ 25.401972] k3s[824]: I1112 11:50:12.156888 824 kubelet_node_status.go:75] "Attempting to register node" node="machine"1265machine # [ 25.403462] k3s[824]: E1112 11:50:12.158471 824 csi_plugin.go:403] Failed to initialize CSINode: error updating CSINode annotation: timed out waiting for the condition; caused by: nodes "machine" not found1266machine # [ 25.419095] k3s[824]: I1112 11:50:12.178121 824 kubelet_node_status.go:78] "Successfully registered node" node="machine"1267machine # [ 25.448113] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Annotations and labels have been set successfully on node: machine"1268machine # [ 25.449948] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Starting flannel with backend vxlan"1269machine # [ 25.541155] k3s[824]: I1112 11:50:12.299480 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="podtemplates"1270machine # [ 25.543596] k3s[824]: I1112 11:50:12.299572 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="horizontalpodautoscalers.autoscaling"1271machine # [ 25.550666] k3s[824]: I1112 11:50:12.299650 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="cronjobs.batch"1272machine # [ 25.553187] k3s[824]: I1112 11:50:12.299686 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="ingresses.networking.k8s.io"1273machine # [ 25.555907] k3s[824]: I1112 11:50:12.299720 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="replicasets.apps"1274machine # [ 25.560164] k3s[824]: I1112 11:50:12.299771 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmcharts.helm.cattle.io"1275machine # [ 25.562532] k3s[824]: I1112 11:50:12.299798 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmchartconfigs.helm.cattle.io"1276machine # [ 25.565887] k3s[824]: I1112 11:50:12.299859 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="addons.k3s.cattle.io"1277machine # [ 25.568575] k3s[824]: I1112 11:50:12.299907 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="networkpolicies.networking.k8s.io"1278machine # [ 25.571246] k3s[824]: I1112 11:50:12.299973 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="roles.rbac.authorization.k8s.io"1279machine # [ 25.573846] k3s[824]: I1112 11:50:12.300013 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpointslices.discovery.k8s.io"1280machine # [ 25.576365] k3s[824]: I1112 11:50:12.300075 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="controllerrevisions.apps"1281machine # [ 25.578868] k3s[824]: I1112 11:50:12.300107 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="daemonsets.apps"1282machine # [ 25.581269] k3s[824]: I1112 11:50:12.300127 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="statefulsets.apps"1283machine # [ 25.583637] k3s[824]: I1112 11:50:12.300152 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="rolebindings.rbac.authorization.k8s.io"1284machine # [ 25.586459] k3s[824]: I1112 11:50:12.300177 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="serviceaccounts"1285machine # [ 25.588758] k3s[824]: I1112 11:50:12.300201 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="jobs.batch"1286machine # [ 25.591196] k3s[824]: I1112 11:50:12.300278 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="limitranges"1287machine # [ 25.593586] k3s[824]: I1112 11:50:12.300303 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="poddisruptionbudgets.policy"1288machine # [ 25.596429] k3s[824]: I1112 11:50:12.300330 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="csistoragecapacities.storage.k8s.io"1289machine # [ 25.599204] k3s[824]: I1112 11:50:12.300358 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="resourceclaimtemplates.resource.k8s.io"1290machine # [ 25.601877] k3s[824]: I1112 11:50:12.300383 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpoints"1291machine # [ 25.604152] k3s[824]: I1112 11:50:12.300406 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="deployments.apps"1292machine # [ 25.606649] k3s[824]: I1112 11:50:12.300437 824 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="leases.coordination.k8s.io"1293machine # [ 25.609155] k3s[824]: I1112 11:50:12.333185 824 kubelet_node_status.go:431] "Fast updating node status as it just became ready"1294machine # [ 25.761945] k3s[824]: I1112 11:50:12.520882 824 apiserver.go:51] "Watching apiserver"1295machine # [ 25.802490] k3s[824]: I1112 11:50:12.561329 824 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world"1296machine # [ 25.826884] k3s[824]: I1112 11:50:12.585958 824 controllermanager.go:689] "Warning: controller is disabled" controller="bootstrap-signer-controller"1297machine # [ 25.969572] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/klipper-helm:v0.13.3-build20260727"1298machine # [ 25.975171] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/klipper-helm@sha256:5425a2b4613d2458dbdff99218e8d487ebb59c20e7a941f061c0777070f0aac1"1299machine # [ 25.978621] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/klipper-lb:v0.4.17"1300machine # [ 25.980560] k3s[824]: I1112 11:50:12.738962 824 controllermanager.go:689] "Warning: controller is disabled" controller="selinux-warning-controller"1301machine # [ 25.986429] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/klipper-lb@sha256:910944bb0bd94f060a82a56ca1ea1c577d3e49b3473a093a47a985f32e92d94a"1302machine # [ 25.988828] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.37"1303machine # [ 25.992544] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/local-path-provisioner@sha256:e757967a5ec338f6a9b371c5a9688bedaa8c3578ea3dd4db329ea0084be0a86f"1304machine # [ 25.995357] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/mirrored-coredns-coredns:1.14.7"1305machine # [ 25.999814] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/mirrored-coredns-coredns@sha256:7efd3c635b03efd68c4e8398fc45f0d993d0e9ab016f72c1cefb0fd6d01aa286"1306machine # [ 26.002760] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/mirrored-library-busybox:1.37.0"1307machine # [ 26.004986] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/mirrored-library-busybox@sha256:101b4afd76732482eff9b95cae5f94bcf295e521fbec4e01b69c5421f3f3f3e5"1308machine # [ 26.007555] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/mirrored-library-traefik:3.7.13"1309machine # [ 26.010135] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/mirrored-library-traefik@sha256:f86a2cab1b5c649070c49f883c743dd32d8485a56e3368c5f93b9e91f1e91259"1310machine # [ 26.013476] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/mirrored-metrics-server:v0.9.0"1311machine # [ 26.015629] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/mirrored-metrics-server@sha256:d9862115e7c7881280d3d75ca26bda8ffc0fc213315979575bf23ce9826205c0"1312machine # [ 26.018119] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported docker.io/rancher/mirrored-pause:3.10.2"1313machine # [ 26.020798] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Tagged docker.io/rancher/mirrored-pause@sha256:f548e0e8e3dc1896ca956272154dde3314e8cc4fde0a57577ee9fa1c63f5baf4"1314machine # [ 26.170967] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Imported 8 images from /var/lib/rancher/k3s/agent/images/nixos/kyix6dphrkrxwz27rcspc3n86sqsafq8-k3s-airgap-images-arm64.tar.zst in 3.70503468s"1315machine # [ 26.173762] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Creating new TLS secret for kube-system/k3s-serving (count: 11): map[listener.cattle.io/cn-10.0.2.15:10.0.2.15 listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-__1-f16284:::1 listener.cattle.io/cn-fec0__b71b_1c7b_77f_2c94-991e88:fec0::b71b:1c7b:77f:2c94 listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/cn-machine:machine listener.cattle.io/fingerprint:SHA1=6D2D705051670B2D49B89BC22EA43E133419F340]"1316machine # [ 26.184340] k3s[824]: time="2026-11-12T11:50:12Z" level=info msg="Active TLS secret kube-system/k3s-serving (ver=255) (count 11): map[listener.cattle.io/cn-10.0.2.15:10.0.2.15 listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-__1-f16284:::1 listener.cattle.io/cn-fec0__b71b_1c7b_77f_2c94-991e88:fec0::b71b:1c7b:77f:2c94 listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/cn-machine:machine listener.cattle.io/fingerprint:SHA1=6D2D705051670B2D49B89BC22EA43E133419F340]"1317machine # [ 26.256637] k3s[824]: I1112 11:50:13.015645 824 server.go:228] "Successfully retrieved NodeIPs" NodeIPs=["10.0.2.15","fec0::b71b:1c7b:77f:2c94"]1318machine # [ 26.259933] k3s[824]: E1112 11:50:13.017043 824 server.go:265] "Kube-proxy configuration may be incomplete or incorrect" err="nodePortAddresses is unset; NodePort connections will be accepted on all local IPs. Consider using `--nodeport-addresses primary`"1319machine # [ 26.289411] k3s[824]: I1112 11:50:13.048413 824 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podgroup-protection-controller" requiredFeatureGates=["GenericWorkload"]1320machine # [ 26.293840] k3s[824]: I1112 11:50:13.048505 824 controllermanager.go:641] "Warning: skipping controller" controller="podgroup-protection-controller"1321machine # [ 26.308274] k3s[824]: I1112 11:50:13.067316 824 server.go:274] "kube-proxy running in dual-stack mode" primary ipFamily="IPv4"1322machine # [ 26.310801] k3s[824]: I1112 11:50:13.067410 824 server_linux.go:137] "Using iptables Proxier"1323machine # [ 26.330472] k3s[824]: I1112 11:50:13.089527 824 node_lifecycle_controller.go:402] "Controller will reconcile labels" logger="node-lifecycle-controller"1324machine # [ 26.333906] k3s[824]: I1112 11:50:13.092442 824 controllermanager.go:689] "Warning: controller is disabled" controller="service-lb-controller"1325machine # [ 26.355258] k3s[824]: I1112 11:50:13.114291 824 proxier.go:241] "Setting route_localnet=1 to allow node-ports on localhost; to change this either disable iptables.localhostNodePorts (--iptables-localhost-nodeports) or set nodePortAddresses (--nodeport-addresses) to filter loopback addresses" ipFamily="IPv4"1326machine # [ 26.370265] k3s[824]: I1112 11:50:13.129175 824 server.go:539] "Version info" version="v1.36.5+k3s1"1327machine # [ 26.371771] k3s[824]: I1112 11:50:13.129217 824 server.go:541] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1328machine # [ 26.381729] k3s[824]: I1112 11:50:13.140784 824 config.go:200] "Starting service config controller"1329machine # [ 26.384092] k3s[824]: I1112 11:50:13.142325 824 shared_informer.go:381] "Waiting for caches to sync" controller="service config"1330machine # [ 26.387057] k3s[824]: I1112 11:50:13.142370 824 config.go:106] "Starting endpoint slice config controller"1331machine # [ 26.389715] k3s[824]: I1112 11:50:13.142412 824 shared_informer.go:381] "Waiting for caches to sync" controller="endpoint slice config"1332machine # [ 26.396208] k3s[824]: I1112 11:50:13.142431 824 config.go:403] "Starting serviceCIDR config controller"1333machine # [ 26.397805] k3s[824]: I1112 11:50:13.142446 824 shared_informer.go:381] "Waiting for caches to sync" controller="serviceCIDR config"1334machine # [ 26.399611] k3s[824]: I1112 11:50:13.145423 824 config.go:309] "Starting node config controller"1335machine # [ 26.401060] k3s[824]: I1112 11:50:13.145471 824 shared_informer.go:381] "Waiting for caches to sync" controller="node config"1336machine # [ 26.403880] k3s[824]: I1112 11:50:13.145502 824 shared_informer.go:388] "Caches are synced" controller="node config"1337machine # [ 26.454586] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller"1338machine # [ 26.460282] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Creating deploy event broadcaster"1339machine # [ 26.466851] k3s[824]: I1112 11:50:13.225932 824 controller.go:667] quota admission added evaluator for: addons.k3s.cattle.io1340machine # [ 26.471579] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Starting /v1, Kind=Node controller"1341machine # [ 26.478545] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Creating helm-controller event broadcaster"1342machine # [ 26.483523] k3s[824]: I1112 11:50:13.242614 824 shared_informer.go:388] "Caches are synced" controller="serviceCIDR config"1343machine # [ 26.487126] k3s[824]: I1112 11:50:13.245845 824 shared_informer.go:388] "Caches are synced" controller="service config"1344machine # [ 26.490309] k3s[824]: I1112 11:50:13.245875 824 shared_informer.go:388] "Caches are synced" controller="endpoint slice config"1345machine # [ 26.506177] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Registered handlers for helm-controller-chart-registration" logger=k3s/helm-controller1346machine # [ 26.515185] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applying manifest at \"/var/lib/rancher/k3s/server/manifests/ccm.yaml\"" object=kube-system/ccm reason=ApplyingManifest type=Normal1347machine # [ 26.585584] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Cluster dns configmap has been set successfully"1348machine # [ 26.587118] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Labels and annotations have been set successfully on node: machine"1349machine # Error from server (NotFound): namespaces "niks3" not found1350machine # [ 26.693593] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applied manifest at \"/var/lib/rancher/k3s/server/manifests/ccm.yaml\"" object=kube-system/ccm reason=AppliedManifest type=Normal1351machine # [ 26.705206] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applying manifest at \"/var/lib/rancher/k3s/server/manifests/ci.yaml\"" object=kube-system/ci reason=ApplyingManifest type=Normal1352machine # [ 26.728107] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applied manifest at \"/var/lib/rancher/k3s/server/manifests/ci.yaml\"" object=kube-system/ci reason=AppliedManifest type=Normal1353machine # [ 26.740266] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applying manifest at \"/var/lib/rancher/k3s/server/manifests/coredns.yaml\"" object=kube-system/coredns reason=ApplyingManifest type=Normal1354machine # [ 26.811824] k3s[824]: I1112 11:50:13.570846 824 controller.go:667] quota admission added evaluator for: deployments.apps1355machine # [ 26.824210] k3s[824]: I1112 11:50:13.583275 824 alloc.go:329] "allocated clusterIPs" service="kube-system/kube-dns" clusterIPs={"IPv4":"10.43.0.10"}1356machine # [ 26.864114] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applied manifest at \"/var/lib/rancher/k3s/server/manifests/coredns.yaml\"" object=kube-system/coredns reason=AppliedManifest type=Normal1357machine # [ 26.978687] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Deleting manifest at \"/var/lib/rancher/k3s/server/manifests/local-storage.yaml\"" object=kube-system/local-storage reason=DeletingManifest type=Normal1358machine # [ 27.008102] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applying manifest at \"/var/lib/rancher/k3s/server/manifests/niks3.yaml\"" object=kube-system/niks3 reason=ApplyingManifest type=Normal1359machine # [ 27.019851] k3s[824]: I1112 11:50:13.778900 824 controller.go:667] quota admission added evaluator for: helmcharts.helm.cattle.io1360machine # [ 27.025056] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applied manifest at \"/var/lib/rancher/k3s/server/manifests/niks3.yaml\"" object=kube-system/niks3 reason=AppliedManifest type=Normal1361machine # [ 27.060275] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applying manifest at \"/var/lib/rancher/k3s/server/manifests/rolebindings.yaml\"" object=kube-system/rolebindings reason=ApplyingManifest type=Normal1362machine # [ 27.115889] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applied manifest at \"/var/lib/rancher/k3s/server/manifests/rolebindings.yaml\"" object=kube-system/rolebindings reason=AppliedManifest type=Normal1363machine # [ 27.145997] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applying manifest at \"/var/lib/rancher/k3s/server/manifests/runtimes.yaml\"" object=kube-system/runtimes reason=ApplyingManifest type=Normal1364machine # [ 27.210814] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Applied manifest at \"/var/lib/rancher/k3s/server/manifests/runtimes.yaml\"" object=kube-system/runtimes reason=AppliedManifest type=Normal1365machine # [ 27.227842] k3s[824]: time="2026-11-12T11:50:13Z" level=info msg="Event occurred" apiVersion=k3s.cattle.io/v1 fieldPath= kind=Addon logger=k3s/deploy message="Deleting manifest at \"/var/lib/rancher/k3s/server/manifests/traefik.yaml\"" object=kube-system/traefik reason=DeletingManifest type=Normal1366machine # [ 27.544169] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Tunnel authorizer set Kubelet Port 0.0.0.0:10250"1367machine # [ 27.660570] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller"1368machine # [ 27.674185] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Starting batch/v1, Kind=Job controller"1369machine # [ 27.675582] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Starting /v1, Kind=ConfigMap controller"1370machine # [ 27.677098] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Starting /v1, Kind=ServiceAccount controller"1371machine # [ 27.678536] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Starting /v1, Kind=Secret controller"1372machine # [ 27.696088] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller"1373machine # [ 27.697623] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller"1374machine # [ 27.740341] k3s[824]: time="2026-11-12T11:50:14Z" level=info msg="Event occurred" apiVersion=helm.cattle.io/v1 fieldPath= kind=HelmChart logger=k3s/helm-controller message="Applying HelmChart from https://%{KUBERNETES_API}%/static/charts/niks3.tgz using Job kube-system/helm-install-niks3 " object=kube-system/niks3 reason=ApplyJob type=Normal1375machine # [ 27.812258] k3s[824]: I1112 11:50:14.571110 824 controller.go:667] quota admission added evaluator for: jobs.batch1376machine # [ 27.866690] k3s[824]: I1112 11:50:14.625728 824 serving.go:417] Generated self-signed cert in-memory1377machine # Error from server (NotFound): namespaces "niks3" not found1378machine # [ 28.077537] k3s[824]: I1112 11:50:14.836252 824 serving.go:417] Generated self-signed cert in-memory1379machine # [ 28.230717] k3s[824]: I1112 11:50:14.989720 824 controllermanager.go:689] "Warning: controller is disabled" controller="cloud-node-lifecycle-controller"1380machine # [ 28.312863] k3s[824]: I1112 11:50:15.071838 824 controllermanager.go:163] Version: v1.36.5+k3s11381machine # [ 28.319298] k3s[824]: I1112 11:50:15.077242 824 secure_serving.go:214] Serving securely on 127.0.0.1:102581382machine # [ 28.321923] k3s[824]: I1112 11:50:15.079471 824 tlsconfig.go:243] "Starting DynamicServingCertificateController"1383machine # [ 28.324352] k3s[824]: I1112 11:50:15.079570 824 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1384machine # [ 28.326857] k3s[824]: I1112 11:50:15.079595 824 shared_informer.go:402] "Waiting for caches to sync"1385machine # [ 28.328997] k3s[824]: I1112 11:50:15.079641 824 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1386machine # [ 28.332706] k3s[824]: I1112 11:50:15.079662 824 shared_informer.go:402] "Waiting for caches to sync"1387machine # [ 28.334803] k3s[824]: I1112 11:50:15.079677 824 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1388machine # [ 28.338737] k3s[824]: I1112 11:50:15.079694 824 shared_informer.go:402] "Waiting for caches to sync"1389machine # [ 28.340889] k3s[824]: time="2026-11-12T11:50:15Z" level=info msg="Creating service-lb-controller event broadcaster"1390machine # [ 28.423235] k3s[824]: I1112 11:50:15.179715 824 shared_informer.go:409] "Caches are synced"1391machine # [ 28.425577] k3s[824]: I1112 11:50:15.179785 824 shared_informer.go:409] "Caches are synced"1392machine # [ 28.427509] k3s[824]: I1112 11:50:15.179763 824 shared_informer.go:409] "Caches are synced"1393machine # [ 28.468407] k3s[824]: time="2026-11-12T11:50:15Z" level=info msg="Starting /v1, Kind=Node controller"1394machine # [ 28.476979] k3s[824]: time="2026-11-12T11:50:15Z" level=info msg="Starting /v1, Kind=Pod controller"1395machine # [ 28.484272] k3s[824]: time="2026-11-12T11:50:15Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller"1396machine # [ 28.491891] k3s[824]: time="2026-11-12T11:50:15Z" level=info msg="Starting discovery.k8s.io/v1, Kind=EndpointSlice controller"1397machine # [ 28.496196] k3s[824]: I1112 11:50:15.250912 824 controllermanager.go:338] Started "cloud-node-controller"1398machine # [ 28.498495] k3s[824]: I1112 11:50:15.254424 824 controllermanager.go:338] Started "cloud-node-lifecycle-controller"1399machine # [ 28.502358] k3s[824]: I1112 11:50:15.251026 824 node_controller.go:179] Sending events to api server.1400machine # [ 28.504664] k3s[824]: I1112 11:50:15.254763 824 node_controller.go:188] Waiting for informer caches to sync1401machine # [ 28.506948] k3s[824]: I1112 11:50:15.254983 824 node_lifecycle_controller.go:112] Sending events to api server1402machine # [ 28.509385] k3s[824]: I1112 11:50:15.255087 824 controllermanager.go:338] Started "service-lb-controller"1403machine # [ 28.511573] k3s[824]: W1112 11:50:15.255113 824 controllermanager.go:315] "node-route-controller" is disabled1404machine # [ 28.513952] k3s[824]: I1112 11:50:15.255258 824 controller.go:235] Starting service controller1405machine # [ 28.515847] k3s[824]: I1112 11:50:15.255298 824 shared_informer.go:402] "Waiting for caches to sync"1406machine # [ 28.529449] k3s[824]: I1112 11:50:15.288283 824 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="resourcepoolstatusrequest-controller" requiredFeatureGates=["DRAResourcePoolStatus"]1407machine # [ 28.533813] k3s[824]: I1112 11:50:15.288367 824 controllermanager.go:641] "Warning: skipping controller" controller="resourcepoolstatusrequest-controller"1408machine # [ 28.596757] k3s[824]: I1112 11:50:15.355527 824 shared_informer.go:409] "Caches are synced"1409machine # [ 28.598865] k3s[824]: I1112 11:50:15.355633 824 node_controller.go:432] Initializing node machine with cloud provider1410machine # [ 28.622501] k3s[824]: I1112 11:50:15.381510 824 node_controller.go:477] Successfully initialized node machine with cloud provider1411machine # [ 28.628311] k3s[824]: I1112 11:50:15.381909 824 event.go:389] "Event occurred" object="machine" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="Synced" message="Node synced successfully"1412machine # [ 28.633774] k3s[824]: E1112 11:50:15.386562 824 options.go:205] The manifest file is empty, ignoring.1413machine # [ 28.635917] k3s[824]: time="2026-11-12T11:50:15Z" level=info msg="Synced coredns NodeHosts entries for machine"1414machine # [ 28.642673] k3s[824]: I1112 11:50:15.401628 824 server.go:176] "Starting Kubernetes Scheduler" version="v1.36.5+k3s1"1415machine # [ 28.645674] k3s[824]: I1112 11:50:15.401717 824 server.go:178] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1416machine # [ 28.651758] k3s[824]: I1112 11:50:15.409280 824 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1417machine # [ 28.657408] k3s[824]: I1112 11:50:15.409357 824 shared_informer.go:402] "Waiting for caches to sync"1418machine # [ 28.659638] k3s[824]: I1112 11:50:15.409422 824 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1419machine # [ 28.669187] k3s[824]: I1112 11:50:15.409444 824 shared_informer.go:402] "Waiting for caches to sync"1420machine # [ 28.671371] k3s[824]: I1112 11:50:15.409463 824 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1421machine # [ 28.675580] k3s[824]: I1112 11:50:15.409493 824 shared_informer.go:402] "Waiting for caches to sync"1422machine # [ 28.680251] k3s[824]: I1112 11:50:15.409739 824 secure_serving.go:214] Serving securely on 127.0.0.1:102591423machine # [ 28.682376] k3s[824]: I1112 11:50:15.409901 824 dynamic_serving_content.go:135] "Starting controller" name="serving-cert::/var/lib/rancher/k3s/server/tls/kube-scheduler/kube-scheduler.crt::/var/lib/rancher/k3s/server/tls/kube-scheduler/kube-scheduler.key"1424machine # [ 28.692703] k3s[824]: I1112 11:50:15.410105 824 tlsconfig.go:243] "Starting DynamicServingCertificateController"1425machine # [ 28.750700] k3s[824]: I1112 11:50:15.509728 824 shared_informer.go:409] "Caches are synced"1426machine # [ 28.753054] k3s[824]: I1112 11:50:15.509786 824 shared_informer.go:409] "Caches are synced"1427machine # [ 28.755159] k3s[824]: I1112 11:50:15.509818 824 shared_informer.go:409] "Caches are synced"1428machine # [ 28.887120] k3s[824]: I1112 11:50:15.646032 824 range_allocator.go:113] "No Secondary Service CIDR provided. Skipping filtering out secondary service addresses" logger="node-ipam-controller"1429machine # [ 29.029483] k3s[824]: I1112 11:50:15.788279 824 controllermanager.go:641] "Warning: skipping controller" controller="storage-version-migrator-controller"1430machine # Error from server (NotFound): namespaces "niks3" not found1431machine # [ 29.650910] k3s[824]: time="2026-11-12T11:50:16Z" level=info msg="Event occurred" apiVersion= fieldPath= kind=Node logger=k3s message="Deferred node password secret validation complete" object=machine reason=NodePasswordValidationComplete type=Normal1432machine # [ 29.688871] k3s[824]: I1112 11:50:16.443138 824 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-legacy-unknown"1433machine # [ 29.691815] k3s[824]: I1112 11:50:16.443223 824 shared_informer.go:402] "Waiting for caches to sync"1434machine # [ 29.694120] k3s[824]: I1112 11:50:16.444510 824 stateful_set.go:234] "Starting stateful set controller"1435machine # [ 29.696232] k3s[824]: I1112 11:50:16.444562 824 shared_informer.go:402] "Waiting for caches to sync"1436machine # [ 29.698239] k3s[824]: I1112 11:50:16.444619 824 endpoints_controller.go:193] "Starting endpoint controller"1437machine # [ 29.700387] k3s[824]: I1112 11:50:16.444650 824 shared_informer.go:402] "Waiting for caches to sync"1438machine # [ 29.702405] k3s[824]: I1112 11:50:16.444721 824 replica_set.go:285] "Starting controller" name="replicationcontroller"1439machine # [ 29.704857] k3s[824]: I1112 11:50:16.444744 824 shared_informer.go:402] "Waiting for caches to sync"1440machine # [ 29.706890] k3s[824]: I1112 11:50:16.444795 824 node_lifecycle_controller.go:436] "Sending events to api server"1441machine # [ 29.709202] k3s[824]: I1112 11:50:16.444840 824 node_lifecycle_controller.go:443] "Starting node controller"1442machine # [ 29.711383] k3s[824]: I1112 11:50:16.444853 824 shared_informer.go:402] "Waiting for caches to sync"1443machine # [ 29.713658] k3s[824]: I1112 11:50:16.444952 824 pv_controller_base.go:318] "Starting persistent volume controller"1444machine # [ 29.717002] k3s[824]: I1112 11:50:16.444971 824 shared_informer.go:402] "Waiting for caches to sync"1445machine # [ 29.719029] k3s[824]: I1112 11:50:16.445001 824 publisher.go:107] "Starting root CA cert publisher controller"1446machine # [ 29.721308] k3s[824]: I1112 11:50:16.445022 824 shared_informer.go:402] "Waiting for caches to sync"1447machine # [ 29.723307] k3s[824]: I1112 11:50:16.445081 824 device_taint_eviction.go:783] "Starting" controller="device-taint-eviction-controller" numWorkers=81448machine # [ 29.726228] k3s[824]: I1112 11:50:16.445447 824 daemon_controller.go:364] "Starting daemon sets controller"1449machine # [ 29.728482] k3s[824]: I1112 11:50:16.445471 824 shared_informer.go:402] "Waiting for caches to sync"1450machine # [ 29.730530] k3s[824]: I1112 11:50:16.445529 824 cronjob_controllerv2.go:143] "Starting cronjob controller v2"1451machine # [ 29.732718] k3s[824]: I1112 11:50:16.445549 824 shared_informer.go:402] "Waiting for caches to sync"1452machine # [ 29.734660] k3s[824]: I1112 11:50:16.445577 824 clusterroleaggregation_controller.go:176] "Starting ClusterRoleAggregator controller"1453machine # [ 29.737184] k3s[824]: I1112 11:50:16.445593 824 shared_informer.go:402] "Waiting for caches to sync"1454machine # [ 29.739201] k3s[824]: I1112 11:50:16.445668 824 vac_protection_controller.go:206] "Starting VAC protection controller"1455machine # [ 29.741446] k3s[824]: I1112 11:50:16.445687 824 shared_informer.go:402] "Waiting for caches to sync"1456machine # [ 29.743213] k3s[824]: I1112 11:50:16.445715 824 ttlafterfinished_controller.go:112] "Starting TTL after finished controller"1457machine # [ 29.745434] k3s[824]: I1112 11:50:16.445728 824 shared_informer.go:402] "Waiting for caches to sync"1458machine # [ 29.747106] k3s[824]: I1112 11:50:16.445796 824 controller.go:753] "Starting resource claim controller"1459machine # [ 29.748922] k3s[824]: I1112 11:50:16.445813 824 shared_informer.go:402] "Waiting for caches to sync"1460machine # [ 29.750670] k3s[824]: I1112 11:50:16.445841 824 serviceaccounts_controller.go:117] "Starting service account controller"1461machine # [ 29.752560] k3s[824]: I1112 11:50:16.445855 824 shared_informer.go:402] "Waiting for caches to sync"1462machine # [ 29.754111] k3s[824]: I1112 11:50:16.445881 824 ttl_controller.go:127] "Starting TTL controller"1463machine # [ 29.755569] k3s[824]: I1112 11:50:16.445898 824 shared_informer.go:402] "Waiting for caches to sync"1464machine # [ 29.757176] k3s[824]: I1112 11:50:16.445954 824 attach_detach_controller.go:334] "Starting attach detach controller"1465machine # [ 29.758847] k3s[824]: I1112 11:50:16.445969 824 shared_informer.go:402] "Waiting for caches to sync"1466machine # [ 29.760355] k3s[824]: I1112 11:50:16.445992 824 expand_controller.go:328] "Starting expand controller"1467machine # [ 29.762033] k3s[824]: I1112 11:50:16.446017 824 shared_informer.go:402] "Waiting for caches to sync"1468machine # [ 29.763494] k3s[824]: I1112 11:50:16.446084 824 servicecidrs_controller.go:137] "Starting" controller="service-cidr-controller"1469machine # [ 29.765397] k3s[824]: I1112 11:50:16.446101 824 shared_informer.go:402] "Waiting for caches to sync"1470machine # [ 29.766798] k3s[824]: I1112 11:50:16.446136 824 certificate_controller.go:120] "Starting certificate controller" name="csrapproving"1471machine # [ 29.768636] k3s[824]: I1112 11:50:16.446155 824 shared_informer.go:402] "Waiting for caches to sync"1472machine # [ 29.770020] k3s[824]: I1112 11:50:16.446258 824 node_ipam_controller.go:142] "Starting ipam controller"1473machine # [ 29.771412] k3s[824]: I1112 11:50:16.446278 824 shared_informer.go:402] "Waiting for caches to sync"1474machine # [ 29.772899] k3s[824]: I1112 11:50:16.446323 824 legacy_serviceaccount_token_cleaner.go:103] "Starting legacy service account token cleaner controller"1475machine # [ 29.774871] k3s[824]: I1112 11:50:16.446340 824 shared_informer.go:402] "Waiting for caches to sync"1476machine # [ 29.776269] k3s[824]: I1112 11:50:16.446402 824 endpointslice_controller.go:280] "Starting endpoint slice controller"1477machine # [ 29.777827] k3s[824]: I1112 11:50:16.446417 824 shared_informer.go:402] "Waiting for caches to sync"1478machine # [ 29.779156] k3s[824]: I1112 11:50:16.446487 824 endpointslicemirroring_controller.go:226] "Starting EndpointSliceMirroring controller"1479machine # [ 29.780941] k3s[824]: I1112 11:50:16.446505 824 shared_informer.go:402] "Waiting for caches to sync"1480machine # [ 29.782221] k3s[824]: I1112 11:50:16.446534 824 gc_controller.go:98] "Starting GC controller"1481machine # [ 29.783489] k3s[824]: I1112 11:50:16.446548 824 shared_informer.go:402] "Waiting for caches to sync"1482machine # [ 29.784849] k3s[824]: I1112 11:50:16.446602 824 deployment_controller.go:180] "Starting controller" controller="deployment"1483machine # [ 29.786430] k3s[824]: I1112 11:50:16.446621 824 shared_informer.go:402] "Waiting for caches to sync"1484machine # [ 29.787676] k3s[824]: I1112 11:50:16.446655 824 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-serving"1485machine # [ 29.789548] k3s[824]: I1112 11:50:16.446668 824 shared_informer.go:402] "Waiting for caches to sync"1486machine # [ 29.790784] k3s[824]: I1112 11:50:16.446697 824 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-client"1487machine # [ 29.792532] k3s[824]: I1112 11:50:16.446715 824 shared_informer.go:402] "Waiting for caches to sync"1488machine # [ 29.793866] k3s[824]: I1112 11:50:16.446736 824 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kube-apiserver-client"1489machine # [ 29.795645] k3s[824]: I1112 11:50:16.446749 824 shared_informer.go:402] "Waiting for caches to sync"1490machine # [ 29.796958] k3s[824]: I1112 11:50:16.446790 824 dynamic_serving_content.go:135] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/server-ca.nochain.crt::/var/lib/rancher/k3s/server/tls/server-ca.key"1491machine # [ 29.799513] k3s[824]: I1112 11:50:16.447077 824 device_taint_eviction.go:823] "Sending events to api server"1492machine # [ 29.800908] k3s[824]: I1112 11:50:16.447240 824 device_taint_eviction.go:1023] "Waiting" for="cache and event handler sync"1493machine # [ 29.802409] k3s[824]: I1112 11:50:16.447324 824 garbagecollector.go:141] "Starting controller" controller="garbagecollector"1494machine # [ 29.804043] k3s[824]: I1112 11:50:16.447348 824 shared_informer.go:402] "Waiting for caches to sync"1495machine # [ 29.805316] k3s[824]: I1112 11:50:16.447424 824 dynamic_serving_content.go:135] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/server-ca.nochain.crt::/var/lib/rancher/k3s/server/tls/server-ca.key"1496machine # [ 29.807903] k3s[824]: I1112 11:50:16.447529 824 dynamic_serving_content.go:135] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/client-ca.nochain.crt::/var/lib/rancher/k3s/server/tls/client-ca.key"1497machine # [ 29.810693] k3s[824]: I1112 11:50:16.447612 824 dynamic_serving_content.go:135] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/client-ca.nochain.crt::/var/lib/rancher/k3s/server/tls/client-ca.key"1498machine # [ 29.813435] k3s[824]: I1112 11:50:16.448086 824 graph_builder.go:387] "Running" component="GraphBuilder"1499machine # [ 29.814845] k3s[824]: I1112 11:50:16.449993 824 shared_informer.go:402] "Waiting for caches to sync"1500machine # [ 29.816119] k3s[824]: I1112 11:50:16.450073 824 cleaner.go:83] "Starting CSR cleaner controller"1501machine # [ 29.817334] k3s[824]: I1112 11:50:16.450133 824 pvc_protection_controller.go:172] "Starting PVC protection controller"1502machine # [ 29.818784] k3s[824]: I1112 11:50:16.450150 824 shared_informer.go:402] "Waiting for caches to sync"1503machine # [ 29.820055] k3s[824]: I1112 11:50:16.450183 824 controller.go:174] "Starting ephemeral volume controller"1504machine # [ 29.821382] k3s[824]: I1112 11:50:16.450198 824 shared_informer.go:402] "Waiting for caches to sync"1505machine # [ 29.822640] k3s[824]: I1112 11:50:16.450220 824 namespace_controller.go:202] "Starting namespace controller"1506machine # [ 29.823979] k3s[824]: I1112 11:50:16.450234 824 shared_informer.go:402] "Waiting for caches to sync"1507machine # [ 29.825450] k3s[824]: I1112 11:50:16.450264 824 horizontal.go:204] "Starting HPA controller"1508machine # [ 29.826622] k3s[824]: I1112 11:50:16.450280 824 shared_informer.go:402] "Waiting for caches to sync"1509machine # [ 29.827864] k3s[824]: I1112 11:50:16.450305 824 pv_protection_controller.go:81] "Starting PV protection controller"1510machine # [ 29.829391] k3s[824]: I1112 11:50:16.450324 824 shared_informer.go:402] "Waiting for caches to sync"1511machine # [ 29.830647] k3s[824]: I1112 11:50:16.450350 824 shared_informer.go:402] "Waiting for caches to sync"1512machine # [ 29.831868] k3s[824]: I1112 11:50:16.450422 824 replica_set.go:285] "Starting controller" name="replicaset"1513machine # [ 29.833261] k3s[824]: I1112 11:50:16.450439 824 shared_informer.go:402] "Waiting for caches to sync"1514machine # [ 29.834490] k3s[824]: I1112 11:50:16.450466 824 disruption.go:453] "Sending events to api server."1515machine # [ 29.835745] k3s[824]: I1112 11:50:16.450501 824 disruption.go:460] "Starting disruption controller"1516machine # [ 29.837064] k3s[824]: I1112 11:50:16.450511 824 shared_informer.go:402] "Waiting for caches to sync"1517machine # [ 29.838302] k3s[824]: I1112 11:50:16.450539 824 taint_eviction.go:283] "Starting" controller="taint-eviction-controller"1518machine # [ 29.839744] k3s[824]: I1112 11:50:16.450582 824 taint_eviction.go:288] "Sending events to API server"1519machine # [ 29.841082] k3s[824]: I1112 11:50:16.450597 824 shared_informer.go:402] "Waiting for caches to sync"1520machine # [ 29.842342] k3s[824]: I1112 11:50:16.450934 824 job_controller.go:336] "Starting job controller"1521machine # [ 29.843548] k3s[824]: I1112 11:50:16.450958 824 shared_informer.go:402] "Waiting for caches to sync"1522machine # [ 29.844868] k3s[824]: I1112 11:50:16.444537 824 tokencleaner.go:117] "Starting token cleaner controller"1523machine # [ 29.846229] k3s[824]: I1112 11:50:16.450991 824 shared_informer.go:402] "Waiting for caches to sync"1524machine # [ 29.847473] k3s[824]: I1112 11:50:16.451402 824 resource_quota_controller.go:297] "Starting resource quota controller"1525machine # [ 29.848990] k3s[824]: I1112 11:50:16.451426 824 shared_informer.go:402] "Waiting for caches to sync"1526machine # [ 29.850251] k3s[824]: I1112 11:50:16.451610 824 resource_quota_monitor.go:309] "QuotaMonitor running"1527machine # [ 29.851502] k3s[824]: I1112 11:50:16.458763 824 shared_informer.go:402] "Waiting for caches to sync"1528machine # [ 29.852858] k3s[824]: I1112 11:50:16.552037 824 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceClaim"1529machine # [ 29.854950] k3s[824]: I1112 11:50:16.552400 824 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.Pod"1530machine # [ 29.857018] k3s[824]: I1112 11:50:16.552498 824 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceSlice + event handler k8s.io/kubernetes/pkg/controller/devicetainteviction.(*Controller).Run"1531machine # [ 29.859993] k3s[824]: I1112 11:50:16.562609 824 shared_informer.go:409] "Caches are synced"1532machine # [ 29.861175] k3s[824]: I1112 11:50:16.562846 824 shared_informer.go:409] "Caches are synced"1533machine # [ 29.862365] k3s[824]: I1112 11:50:16.567247 824 shared_informer.go:409] "Caches are synced"1534machine # [ 29.863531] k3s[824]: I1112 11:50:16.567297 824 shared_informer.go:409] "Caches are synced"1535machine # [ 29.864762] k3s[824]: I1112 11:50:16.568087 824 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceClaim + event handler k8s.io/kubernetes/pkg/controller/devicetainteviction.(*Controller).Run"1536machine # [ 29.867861] k3s[824]: I1112 11:50:16.568168 824 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.Pod + event handler k8s.io/kubernetes/pkg/controller/devicetainteviction.(*Controller).Run"1537machine # [ 29.871004] k3s[824]: I1112 11:50:16.568208 824 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceSlice"1538machine # [ 29.873321] k3s[824]: I1112 11:50:16.585116 824 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.DeviceClass"1539machine # [ 29.875391] k3s[824]: I1112 11:50:16.617411 824 actual_state_of_world.go:541] "Failed to update statusUpdateNeeded field in actual state of world" logger="persistentvolume-attach-detach-controller" err="Failed to set statusUpdateNeeded to needed true, because nodeName=\"machine\" does not exist"1540machine # [ 29.888110] k3s[824]: I1112 11:50:16.644345 824 shared_informer.go:409] "Caches are synced"1541machine # [ 29.889491] k3s[824]: I1112 11:50:16.645393 824 shared_informer.go:409] "Caches are synced"1542machine # [ 29.890686] k3s[824]: I1112 11:50:16.645591 824 shared_informer.go:409] "Caches are synced"1543machine # [ 29.891852] k3s[824]: I1112 11:50:16.645717 824 shared_informer.go:409] "Caches are synced"1544machine # [ 29.893124] k3s[824]: I1112 11:50:16.645737 824 shared_informer.go:409] "Caches are synced"1545machine # [ 29.894311] k3s[824]: I1112 11:50:16.645764 824 shared_informer.go:409] "Caches are synced"1546machine # [ 29.895505] k3s[824]: I1112 11:50:16.645788 824 shared_informer.go:409] "Caches are synced"1547machine # [ 29.900112] k3s[824]: I1112 11:50:16.645810 824 shared_informer.go:409] "Caches are synced"1548machine # [ 29.901350] k3s[824]: I1112 11:50:16.645877 824 node_lifecycle_controller.go:1217] "Initializing eviction metric for zone" zone=""1549machine # [ 29.902967] k3s[824]: I1112 11:50:16.645928 824 shared_informer.go:409] "Caches are synced"1550machine # [ 29.908152] k3s[824]: I1112 11:50:16.646524 824 shared_informer.go:409] "Caches are synced"1551machine # [ 29.909409] k3s[824]: I1112 11:50:16.646559 824 shared_informer.go:409] "Caches are synced"1552machine # [ 29.910591] k3s[824]: I1112 11:50:16.646579 824 shared_informer.go:409] "Caches are synced"1553machine # [ 29.911763] k3s[824]: I1112 11:50:16.646604 824 shared_informer.go:409] "Caches are synced"1554machine # [ 29.914308] k3s[824]: I1112 11:50:16.646660 824 shared_informer.go:409] "Caches are synced"1555machine # [ 29.915598] k3s[824]: I1112 11:50:16.656839 824 shared_informer.go:409] "Caches are synced"1556machine # [ 29.917927] k3s[824]: I1112 11:50:16.658848 824 shared_informer.go:409] "Caches are synced"1557machine # [ 29.919123] k3s[824]: I1112 11:50:16.659153 824 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161558machine # [ 29.924115] k3s[824]: I1112 11:50:16.663513 824 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161559machine # [ 29.925793] k3s[824]: I1112 11:50:16.663827 824 shared_informer.go:409] "Caches are synced"1560machine # [ 29.926965] k3s[824]: I1112 11:50:16.664840 824 node_lifecycle_controller.go:869] "Missing timestamp for Node. Assuming now as a timestamp" node="machine"1561machine # [ 29.932230] k3s[824]: I1112 11:50:16.664898 824 node_lifecycle_controller.go:1063] "Controller detected that zone is now in new state" zone="" newState="Normal"1562machine # [ 29.934150] k3s[824]: I1112 11:50:16.664940 824 shared_informer.go:409] "Caches are synced"1563machine # [ 29.935327] k3s[824]: I1112 11:50:16.666503 824 shared_informer.go:409] "Caches are synced"1564machine # [ 29.936528] k3s[824]: I1112 11:50:16.666662 824 shared_informer.go:409] "Caches are synced"1565machine # [ 29.937691] k3s[824]: I1112 11:50:16.666717 824 shared_informer.go:409] "Caches are synced"1566machine # [ 29.938841] k3s[824]: I1112 11:50:16.666737 824 shared_informer.go:409] "Caches are synced"1567machine # [ 29.944139] k3s[824]: I1112 11:50:16.666781 824 range_allocator.go:177] "Sending events to api server"1568machine # [ 29.945467] k3s[824]: I1112 11:50:16.666814 824 range_allocator.go:181] "Starting range CIDR allocator"1569machine # [ 29.946761] k3s[824]: I1112 11:50:16.666821 824 shared_informer.go:402] "Waiting for caches to sync"1570machine # [ 29.948061] k3s[824]: I1112 11:50:16.666828 824 shared_informer.go:409] "Caches are synced"1571machine # [ 29.949979] k3s[824]: I1112 11:50:16.672276 824 shared_informer.go:409] "Caches are synced"1572machine # [ 29.951218] k3s[824]: I1112 11:50:16.672861 824 shared_informer.go:409] "Caches are synced"1573machine # [ 29.952456] k3s[824]: I1112 11:50:16.672885 824 shared_informer.go:409] "Caches are synced"1574machine # [ 29.953711] k3s[824]: I1112 11:50:16.672906 824 shared_informer.go:409] "Caches are synced"1575machine # [ 29.954913] k3s[824]: I1112 11:50:16.672936 824 shared_informer.go:409] "Caches are synced"1576machine # [ 29.956164] k3s[824]: I1112 11:50:16.675981 824 shared_informer.go:402] "Waiting for caches to sync"1577machine # [ 29.957450] k3s[824]: I1112 11:50:16.676358 824 shared_informer.go:409] "Caches are synced"1578machine # [ 29.958636] k3s[824]: I1112 11:50:16.676418 824 shared_informer.go:409] "Caches are synced"1579machine # [ 29.959823] k3s[824]: I1112 11:50:16.676515 824 shared_informer.go:409] "Caches are synced"1580machine # [ 29.964266] k3s[824]: I1112 11:50:16.676545 824 shared_informer.go:409] "Caches are synced"1581machine # [ 29.965483] k3s[824]: I1112 11:50:16.676603 824 shared_informer.go:409] "Caches are synced"1582machine # [ 29.966644] k3s[824]: I1112 11:50:16.676638 824 shared_informer.go:409] "Caches are synced"1583machine # [ 29.967809] k3s[824]: I1112 11:50:16.676657 824 shared_informer.go:409] "Caches are synced"1584machine # [ 29.969085] k3s[824]: I1112 11:50:16.676680 824 shared_informer.go:409] "Caches are synced"1585machine # [ 29.970250] k3s[824]: I1112 11:50:16.676723 824 shared_informer.go:409] "Caches are synced"1586machine # [ 29.971404] k3s[824]: I1112 11:50:16.676766 824 shared_informer.go:409] "Caches are synced"1587machine # [ 29.976181] k3s[824]: I1112 11:50:16.676799 824 shared_informer.go:409] "Caches are synced"1588machine # [ 29.977442] k3s[824]: time="2026-11-12T11:50:16Z" level=info msg="Adding node OwnerReference to node-password secret machine.node-password.k3s"1589machine # [ 29.979160] k3s[824]: time="2026-11-12T11:50:16Z" level=info msg="Flannel found PodCIDR assigned for node machine"1590machine # [ 29.980646] k3s[824]: time="2026-11-12T11:50:16Z" level=info msg="The interface eth0 with ipv4 address 10.0.2.15 will be used by flannel"1591machine # [ 29.982297] k3s[824]: I1112 11:50:16.722875 824 kube.go:139] Waiting 10m0s for node controller to sync1592machine # [ 29.983618] k3s[824]: I1112 11:50:16.723003 824 kube.go:537] Starting kube subnet manager1593machine # [ 29.984862] k3s[824]: I1112 11:50:16.731081 824 range_allocator.go:433] "Set node PodCIDR" node="machine" podCIDRs=["10.42.0.0/24"]1594machine # Error from server (NotFound): namespaces "niks3" not found1595machine # [ 30.481035] k3s[824]: I1112 11:50:17.240043 824 controller.go:667] quota admission added evaluator for: replicasets.apps1596machine # [ 30.543944] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Started tunnel to 10.0.2.15:6443"1597machine # [ 30.546122] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Stopped tunnel to 127.0.0.1:6443"1598machine # [ 30.548110] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Connecting to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1599machine # [ 30.550573] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"1600machine # [ 30.553428] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"1601machine # [ 30.556394] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Handling backend connection request [machine]"1602machine # [ 30.558558] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1603machine # [ 30.561015] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Remotedialer connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1604machine # [ 30.806895] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Event occurred" apiVersion=helm.cattle.io/v1 fieldPath= kind=HelmChart logger=k3s/helm-controller message="Resumed synced Job kube-system/helm-install-niks3" object=kube-system/niks3 reason=ResumeJob type=Normal1605machine # [ 30.856383] systemd[1]: Created slice libcontainer container kubepods-burstable-podfbe92022_3be2_46da_8225_ca9b4fc813e9.slice.1606machine # [ 30.896133] k3s[824]: I1112 11:50:17.652159 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-config\") pod \"helm-install-niks3-5cxkq\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") " pod="kube-system/helm-install-niks3-5cxkq"1607machine # [ 30.904197] k3s[824]: I1112 11:50:17.652217 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-tmp\") pod \"helm-install-niks3-5cxkq\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") " pod="kube-system/helm-install-niks3-5cxkq"1608machine # [ 30.911229] k3s[824]: I1112 11:50:17.652255 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"values\" (UniqueName: \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-values\") pod \"helm-install-niks3-5cxkq\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") " pod="kube-system/helm-install-niks3-5cxkq"1609machine # [ 30.922207] k3s[824]: I1112 11:50:17.652278 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"content\" (UniqueName: \"kubernetes.io/configmap/fbe92022-3be2-46da-8225-ca9b4fc813e9-content\") pod \"helm-install-niks3-5cxkq\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") " pod="kube-system/helm-install-niks3-5cxkq"1610machine # [ 30.929006] k3s[824]: I1112 11:50:17.652304 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-9pj7h\" (UniqueName: \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-kube-api-access-9pj7h\") pod \"helm-install-niks3-5cxkq\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") " pod="kube-system/helm-install-niks3-5cxkq"1611machine # [ 30.938566] k3s[824]: I1112 11:50:17.652328 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-helm\") pod \"helm-install-niks3-5cxkq\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") " pod="kube-system/helm-install-niks3-5cxkq"1612machine # [ 30.947976] k3s[824]: I1112 11:50:17.652351 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-cache\") pod \"helm-install-niks3-5cxkq\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") " pod="kube-system/helm-install-niks3-5cxkq"1613machine # [ 30.956202] k3s[824]: E1112 11:50:17.652372 824 replica_set.go:640] "Unhandled Error" err="sync \"kube-system/coredns-7cfb7bc9c7\" failed with read version: 364 is not as new as written version: 394 for group resource replicasets.apps" logger="UnhandledError"1614machine # [ 30.961020] systemd[1]: Created slice libcontainer container kubepods-burstable-pod8c52c01a_8308_4a5d_b49d_05574ca01d94.slice.1615machine # [ 30.966695] k3s[824]: I1112 11:50:17.723603 824 kube.go:163] Node controller sync successful1616machine # [ 30.968114] k3s[824]: I1112 11:50:17.723683 824 vxlan.go:128] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false1617machine # [ 30.969873] k3s[824]: I1112 11:50:17.725598 824 kube.go:704] List of node(machine) annotations: map[string]string{"alpha.kubernetes.io/provided-node-ip":"10.0.2.15,fec0::b71b:1c7b:77f:2c94", "k3s.io/hostname":"machine", "k3s.io/internal-ip":"10.0.2.15,fec0::b71b:1c7b:77f:2c94", "k3s.io/node-args":"[\"server\",\"--disable\",\"traefik\",\"--disable\",\"metrics-server\",\"--disable\",\"local-storage\"]", "k3s.io/node-config-hash":"B5VKUCD5GTR3QGINHIAWYQ4H226RXO3OMZ3SDCJYGSY4JRMNFBRQ====", "k3s.io/node-env":"{}", "node.alpha.kubernetes.io/ttl":"0", "volumes.kubernetes.io/controller-managed-attach-detach":"true"}1618machine # [ 30.997787] k3s[824]: I1112 11:50:17.755254 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"config-volume\" (UniqueName: \"kubernetes.io/configmap/8c52c01a-8308-4a5d-b49d-05574ca01d94-config-volume\") pod \"coredns-7cfb7bc9c7-gflnh\" (UID: \"8c52c01a-8308-4a5d-b49d-05574ca01d94\") " pod="kube-system/coredns-7cfb7bc9c7-gflnh"1619machine # [ 31.005087] k3s[824]: I1112 11:50:17.755460 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"custom-config-volume\" (UniqueName: \"kubernetes.io/configmap/8c52c01a-8308-4a5d-b49d-05574ca01d94-custom-config-volume\") pod \"coredns-7cfb7bc9c7-gflnh\" (UID: \"8c52c01a-8308-4a5d-b49d-05574ca01d94\") " pod="kube-system/coredns-7cfb7bc9c7-gflnh"1620machine # [ 31.012709] k3s[824]: I1112 11:50:17.755728 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-l8jq4\" (UniqueName: \"kubernetes.io/projected/8c52c01a-8308-4a5d-b49d-05574ca01d94-kube-api-access-l8jq4\") pod \"coredns-7cfb7bc9c7-gflnh\" (UID: \"8c52c01a-8308-4a5d-b49d-05574ca01d94\") " pod="kube-system/coredns-7cfb7bc9c7-gflnh"1621machine # [ 31.040510] k3s[824]: I1112 11:50:17.799582 824 iptables.go:50] Starting flannel in iptables mode...1622machine # [ 31.044745] k3s[824]: time="2026-11-12T11:50:17Z" level=warning msg="no subnet found for key: FLANNEL_NETWORK in file: /run/flannel/subnet.env"1623machine # [ 31.049713] k3s[824]: time="2026-11-12T11:50:17Z" level=warning msg="no subnet found for key: FLANNEL_SUBNET in file: /run/flannel/subnet.env"1624machine # [ 31.052434] k3s[824]: time="2026-11-12T11:50:17Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_NETWORK in file: /run/flannel/subnet.env"1625machine # [ 31.056150] k3s[824]: time="2026-11-12T11:50:17Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_SUBNET in file: /run/flannel/subnet.env"1626machine # [ 31.058329] k3s[824]: I1112 11:50:17.805886 824 iptables.go:101] Current network or subnet (10.42.0.0/16, 10.42.0.0/24) is not equal to previous one (0.0.0.0/0, 0.0.0.0/0), trying to recycle old iptables rules1627machine # [ 31.061684] k3s[824]: I1112 11:50:17.807492 824 kube.go:558] Creating the node lease for IPv4. This is the n.Spec.PodCIDRs: [10.42.0.0/24]1628machine # [ 31.088564] k3s[824]: I1112 11:50:17.847579 824 shared_informer.go:409] "Caches are synced"1629machine # [ 31.091008] k3s[824]: I1112 11:50:17.847602 824 garbagecollector.go:166] "Garbage collector: all resource monitors have synced"1630machine # [ 31.095323] k3s[824]: I1112 11:50:17.847609 824 garbagecollector.go:169] "Proceeding to collect garbage"1631machine # [ 31.102149] (udev-worker)[1179]: Network interface NamePolicy= disabled on kernel command line.1632machine # [ 31.117594] k3s[824]: I1112 11:50:17.876678 824 shared_informer.go:409] "Caches are synced"1633machine # [ 31.118864] k3s[824]: I1112 11:50:17.877501 824 iptables.go:111] Setting up masking rules1634machine # [ 31.134072] k3s[824]: I1112 11:50:17.893158 824 iptables.go:212] Changing default FORWARD chain policy to ACCEPT1635machine # [ 31.142109] dhcpcd[585]: flannel.1: IAID 7d:e1:3d:a81636machine # [ 31.142918] dhcpcd[585]: flannel.1: adding address fe80::83a:7dff:fee1:3da81637machine # [ 31.146898] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Wrote flannel subnet file to /run/flannel/subnet.env"1638machine # [ 31.148499] k3s[824]: time="2026-11-12T11:50:17Z" level=info msg="Running flannel backend"1639machine # [ 31.149773] k3s[824]: I1112 11:50:17.905979 824 vxlan_network.go:68] watching for new subnet leases1640machine # [ 31.151270] k3s[824]: I1112 11:50:17.906271 824 vxlan_network.go:115] starting vxlan device watcher1641machine # [ 31.188505] k3s[824]: I1112 11:50:17.947549 824 iptables.go:358] bootstrap done1642machine # [ 31.245245] (udev-worker)[1176]: Network interface NamePolicy= disabled on kernel command line.1643machine # [ 31.270012] (udev-worker)[1177]: Network interface NamePolicy= disabled on kernel command line.1644machine # [ 31.279754] cni0: port 1(veth9bf9e146) entered blocking state1645machine # [ 31.279784] cni0: port 1(veth9bf9e146) entered disabled state1646machine # [ 31.279817] veth9bf9e146: entered allmulticast mode1647machine # [ 31.279917] veth9bf9e146: entered promiscuous mode1648machine # [ 31.279092] k3s[824]: I1112 11:50:18.035955 824 iptables.go:358] bootstrap done1649machine # [ 31.314004] cni0: port 1(veth9bf9e146) entered blocking state1650machine # [ 31.314037] cni0: port 1(veth9bf9e146) entered forwarding state1651machine # [ 31.344341] cni0: port 2(vethc6c77eca) entered blocking state1652machine # [ 31.344372] cni0: port 2(vethc6c77eca) entered disabled state1653machine # [ 31.344418] vethc6c77eca: entered allmulticast mode1654machine # [ 31.344524] vethc6c77eca: entered promiscuous mode1655machine # [ 31.370556] cni0: port 2(vethc6c77eca) entered blocking state1656machine # [ 31.370585] cni0: port 2(vethc6c77eca) entered forwarding state1657machine # [ 31.372154] dhcpcd[585]: veth9bf9e146: waiting for carrier1658machine # [ 31.390208] dhcpcd[585]: vethc6c77eca: IAID f6:12:5a:e51659machine # [ 31.391914] dhcpcd[585]: vethc6c77eca: adding address fe80::86f:f6ff:fe12:5ae51660machine # [ 31.393879] dhcpcd[585]: veth9bf9e146: carrier acquired1661machine # [ 31.400461] dhcpcd[585]: veth9bf9e146: IAID 76:80:59:3e1662machine # [ 31.401393] dhcpcd[585]: veth9bf9e146: adding address fe80::186b:76ff:fe80:593e1663machine # [ 31.403060] dhcpcd[585]: vethc6c77eca: old hardware address: 0a:6f:f6:12:5a:e51664machine # [ 31.404731] dhcpcd[585]: vethc6c77eca: new hardware address: 16:f3:9d:c9:37:a31665machine # [ 31.406050] dhcpcd[585]: vethc6c77eca: carrier lost1666machine # [ 31.438785] dhcpcd[585]: vethc6c77eca: deleting address fe80::86f:f6ff:fe12:5ae51667machine # [ 31.440352] dhcpcd[585]: vethc6c77eca: old hardware address: 16:f3:9d:c9:37:a31668machine # [ 31.442312] dhcpcd[585]: vethc6c77eca: new hardware address: 0a:6f:f6:12:5a:e51669machine # [ 31.443743] dhcpcd[585]: vethc6c77eca: carrier acquired1670machine # [ 31.451071] dhcpcd[585]: vethc6c77eca: IAID f6:12:5a:e51671machine # [ 31.451964] dhcpcd[585]: vethc6c77eca: adding address fe80::86f:f6ff:fe12:5ae51672machine # [ 31.548544] systemd[1]: Started libcontainer container 9103075f5c5199c093c2492e0c4221e01e588b4638e6d9d398dfeb249e48978a.1673machine # [ 31.555020] systemd[1]: Started libcontainer container cde0fbb86775d96bf64dc733f05f0a25f99b03685167900090f5e30667191bb9.1674machine # Error from server (NotFound): namespaces "niks3" not found1675machine # [ 31.869894] dhcpcd[585]: vethc6c77eca: soliciting a DHCP lease1676machine # [ 31.967817] dhcpcd[585]: flannel.1: soliciting a DHCP lease1677machine # [ 32.054383] dhcpcd[585]: veth9bf9e146: soliciting a DHCP lease1678machine # [ 32.147642] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount2490022820.mount: Deactivated successfully.1679machine # Error from server (NotFound): namespaces "niks3" not found1680machine # [ 33.166490] dhcpcd[585]: flannel.1: soliciting an IPv6 router1681machine # [ 33.188767] systemd[1]: Started libcontainer container d6037185821c925697127a1eaf7e51cce8e48df9c83350e9e8778759d55e7f96.1682machine # [ 33.221845] dhcpcd[585]: veth9bf9e146: soliciting an IPv6 router1683machine # [ 33.477954] dhcpcd[585]: vethc6c77eca: soliciting an IPv6 router1684machine # [ 33.482839] k3s[824]: I1112 11:50:20.241310 824 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/coredns-7cfb7bc9c7-gflnh" podStartSLOduration=3.24128588 podStartE2EDuration="3.24128588s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 11:50:17 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 11:50:20.03898448 +0000 UTC m=+15.423011201" watchObservedRunningTime="2026-11-12 11:50:20.24128588 +0000 UTC m=+15.625312621"1685machine # [ 33.580705] systemd[1]: Started libcontainer container 8216663079187e1c76b1c39ae59cf3a675a9985c86079116c70048d31409f3fe.1686machine # Error from server (NotFound): namespaces "niks3" not found1687machine # [ 34.476709] k3s[824]: I1112 11:50:21.235721 824 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/helm-install-niks3-5cxkq" podStartSLOduration=4.23569866 podStartE2EDuration="4.23569866s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 11:50:17 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 11:50:20.44284414 +0000 UTC m=+15.826870861" watchObservedRunningTime="2026-11-12 11:50:21.23569866 +0000 UTC m=+16.619725381"1688machine # [ 34.488802] k3s[824]: I1112 11:50:21.240023 824 alloc.go:329] "allocated clusterIPs" service="niks3/niks3" clusterIPs={"IPv4":"10.43.128.220"}1689machine # [ 34.504086] k3s[824]: I1112 11:50:21.260377 824 controller.go:667] quota admission added evaluator for: cronjobs.batch1690machine # [ 34.522698] k3s[824]: E1112 11:50:21.281676 824 replica_set.go:640] "Unhandled Error" err="sync \"niks3/niks3-688c9f4967\" failed with read version: 438 is not as new as written version: 445 for group resource replicasets.apps" logger="UnhandledError"1691machine # [ 34.527763] k3s[824]: E1112 11:50:21.286851 824 replica_set.go:640] "Unhandled Error" err="sync \"niks3/niks3-688c9f4967\" failed with read version: 438 is not as new as written version: 445 for group resource replicasets.apps" logger="UnhandledError"1692machine # [ 34.540781] k3s[824]: E1112 11:50:21.297015 824 replica_set.go:640] "Unhandled Error" err="sync \"niks3/niks3-688c9f4967\" failed with read version: 438 is not as new as written version: 445 for group resource replicasets.apps" logger="UnhandledError"1693machine # [ 34.558771] systemd[1]: cri-containerd-8216663079187e1c76b1c39ae59cf3a675a9985c86079116c70048d31409f3fe.scope: Deactivated successfully.1694machine # [ 34.562521] systemd[1]: cri-containerd-8216663079187e1c76b1c39ae59cf3a675a9985c86079116c70048d31409f3fe.scope: Consumed 841ms CPU time over 977ms wall clock time, 39.9M memory peak, 4.5M incoming IP traffic, 101.3K outgoing IP traffic.1695machine # [ 34.575963] k3s[824]: E1112 11:50:21.335035 824 status_manager.go:1164] "Failed to get status for pod" err="pods \"niks3-688c9f4967-gpf8n\" is forbidden: User \"system:node:machine\" cannot get resource \"pods\" in API group \"\" in the namespace \"niks3\": no relationship found between node 'machine' and this object" podUID="cb04ec61-002a-45ab-89be-4351c6e4ca13" pod="niks3/niks3-688c9f4967-gpf8n"1696machine # [ 34.590641] systemd[1]: Created slice libcontainer container kubepods-besteffort-podcb04ec61_002a_45ab_89be_4351c6e4ca13.slice.1697machine # [ 34.633504] k3s[824]: I1112 11:50:21.392561 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-j67f4\" (UniqueName: \"kubernetes.io/projected/cb04ec61-002a-45ab-89be-4351c6e4ca13-kube-api-access-j67f4\") pod \"niks3-688c9f4967-gpf8n\" (UID: \"cb04ec61-002a-45ab-89be-4351c6e4ca13\") " pod="niks3/niks3-688c9f4967-gpf8n"1698machine # [ 34.639862] k3s[824]: I1112 11:50:21.392608 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"db\" (UniqueName: \"kubernetes.io/secret/cb04ec61-002a-45ab-89be-4351c6e4ca13-db\") pod \"niks3-688c9f4967-gpf8n\" (UID: \"cb04ec61-002a-45ab-89be-4351c6e4ca13\") " pod="niks3/niks3-688c9f4967-gpf8n"1699machine # [ 34.648699] k3s[824]: I1112 11:50:21.392630 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"s3\" (UniqueName: \"kubernetes.io/secret/cb04ec61-002a-45ab-89be-4351c6e4ca13-s3\") pod \"niks3-688c9f4967-gpf8n\" (UID: \"cb04ec61-002a-45ab-89be-4351c6e4ca13\") " pod="niks3/niks3-688c9f4967-gpf8n"1700machine # [ 34.652792] k3s[824]: I1112 11:50:21.392706 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"oidc\" (UniqueName: \"kubernetes.io/configmap/cb04ec61-002a-45ab-89be-4351c6e4ca13-oidc\") pod \"niks3-688c9f4967-gpf8n\" (UID: \"cb04ec61-002a-45ab-89be-4351c6e4ca13\") " pod="niks3/niks3-688c9f4967-gpf8n"1701machine # [ 34.658097] k3s[824]: I1112 11:50:21.392727 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/cb04ec61-002a-45ab-89be-4351c6e4ca13-token\") pod \"niks3-688c9f4967-gpf8n\" (UID: \"cb04ec61-002a-45ab-89be-4351c6e4ca13\") " pod="niks3/niks3-688c9f4967-gpf8n"1702machine # [ 34.673526] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-8216663079187e1c76b1c39ae59cf3a675a9985c86079116c70048d31409f3fe-rootfs.mount: Deactivated successfully.1703machine # [ 34.961317] cni0: port 3(veth3cfc5b83) entered blocking state1704machine # [ 34.961358] cni0: port 3(veth3cfc5b83) entered disabled state1705machine # [ 34.961393] veth3cfc5b83: entered allmulticast mode1706machine # [ 34.961595] veth3cfc5b83: entered promiscuous mode1707machine # [ 34.961891] (udev-worker)[1556]: Network interface NamePolicy= disabled on kernel command line.1708machine # [ 34.987400] cni0: port 3(veth3cfc5b83) entered blocking state1709machine # [ 34.987442] cni0: port 3(veth3cfc5b83) entered forwarding state1710machine # [ 35.012310] dhcpcd[585]: veth3cfc5b83: IAID f7:0e:91:881711machine # [ 35.013383] dhcpcd[585]: veth3cfc5b83: adding address fe80::407:f7ff:fe0e:91881712machine # [ 35.107180] dhcpcd[585]: veth3cfc5b83: soliciting a DHCP lease1713machine # [ 35.112481] systemd[1]: Started libcontainer container 8e77ed768dbeec1a6013288ff8f3ef1890959354bdb393502a24dc53cf8c5b7a.1714machine # [ 35.596410] k3s[824]: I1112 11:50:22.355004 824 kuberuntime_manager.go:2172] "Updating runtime config through cri with podcidr" CIDR="10.42.0.0/24"1715machine # [ 35.600569] k3s[824]: I1112 11:50:22.359607 824 kubelet_network.go:48] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="10.42.0.0/24"1716machine # [ 35.840776] systemd[1]: Started libcontainer container 20b68b93347d4909d06e3df65225ad86ca5bc537d3f8735b7fc2542e37b2156c.1717machine # [ 36.033777] k3s[824]: time="2026-11-12T11:50:22Z" level=info msg="Starting network policy controller version v2.6.3-k3s1, built on 1970-01-01T01:01:01Z, go1.26.10"1718machine # [ 36.038468] k3s[824]: I1112 11:50:22.792825 824 network_policy_controller.go:164] Starting network policy controller1719machine # [ 36.205103] k3s[824]: I1112 11:50:22.964147 824 network_policy_controller.go:179] Starting network policy controller full sync goroutine1720machine # [ 36.558335] systemd[1]: cri-containerd-cde0fbb86775d96bf64dc733f05f0a25f99b03685167900090f5e30667191bb9.scope: Deactivated successfully.1721machine # [ 36.613379] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-cde0fbb86775d96bf64dc733f05f0a25f99b03685167900090f5e30667191bb9-rootfs.mount: Deactivated successfully.1722machine # [ 36.707768] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-cde0fbb86775d96bf64dc733f05f0a25f99b03685167900090f5e30667191bb9-shm.mount: Deactivated successfully.1723machine # [ 36.750748] dhcpcd[585]: veth9bf9e146: carrier lost[ 36.756537] cni0: port 1(veth9bf9e146) entered disabled state1724machine # 1725machine # [ 36.758334] veth9bf9e146 (unregistering): left allmulticast mode1726machine # [ 36.758361] veth9bf9e146 (unregistering): left promiscuous mode1727machine # [ 36.758372] cni0: port 1(veth9bf9e146) entered disabled state1728machine # [ 36.782486] dhcpcd[585]: veth9bf9e146: deleting address fe80::186b:76ff:fe80:593e1729machine # [ 36.794064] systemd[1]: run-netns-cni\x2d0a415336\x2d0905\x2dac05\x2d3dfa\x2dbadf049965d2.mount: Deactivated successfully.1730machine # [ 36.831396] k3s[824]: I1112 11:50:23.588535 824 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-688c9f4967-gpf8n" podStartSLOduration=2.5885040200000002 podStartE2EDuration="2.58850402s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 11:50:21 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 11:50:22.69883596 +0000 UTC m=+18.082862681" watchObservedRunningTime="2026-11-12 11:50:23.58850402 +0000 UTC m=+18.972530741"1731machine # [ 36.840433] dhcpcd[585]: veth9bf9e146: removing interface1732machine # [ 36.870129] dhcpcd[585]: vethc6c77eca: probing for an IPv4LL address1733machine # [ 36.922917] k3s[824]: I1112 11:50:23.681974 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-cache\") pod \"fbe92022-3be2-46da-8225-ca9b4fc813e9\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") "1734machine # [ 36.929669] k3s[824]: I1112 11:50:23.682016 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-config\") pod \"fbe92022-3be2-46da-8225-ca9b4fc813e9\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") "1735machine # [ 36.937853] k3s[824]: I1112 11:50:23.682047 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/configmap/fbe92022-3be2-46da-8225-ca9b4fc813e9-content\" (UniqueName: \"kubernetes.io/configmap/fbe92022-3be2-46da-8225-ca9b4fc813e9-content\") pod \"fbe92022-3be2-46da-8225-ca9b4fc813e9\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") "1736machine # [ 36.944798] k3s[824]: I1112 11:50:23.682071 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-kube-api-access-9pj7h\" (UniqueName: \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-kube-api-access-9pj7h\") pod \"fbe92022-3be2-46da-8225-ca9b4fc813e9\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") "1737machine # [ 36.953959] k3s[824]: I1112 11:50:23.682099 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-helm\") pod \"fbe92022-3be2-46da-8225-ca9b4fc813e9\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") "1738machine # [ 36.959279] k3s[824]: I1112 11:50:23.682128 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-tmp\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-tmp\") pod \"fbe92022-3be2-46da-8225-ca9b4fc813e9\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") "1739machine # [ 36.964317] k3s[824]: I1112 11:50:23.682150 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-values\" (UniqueName: \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-values\") pod \"fbe92022-3be2-46da-8225-ca9b4fc813e9\" (UID: \"fbe92022-3be2-46da-8225-ca9b4fc813e9\") "1740machine # [ 36.969193] k3s[824]: I1112 11:50:23.688183 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-values" pod "fbe92022-3be2-46da-8225-ca9b4fc813e9" (UID: "fbe92022-3be2-46da-8225-ca9b4fc813e9"). InnerVolumeSpecName "values". PluginName "kubernetes.io/projected", VolumeGIDValue ""1741machine # [ 36.974129] systemd[1]: var-lib-kubelet-pods-fbe92022\x2d3be2\x2d46da\x2d8225\x2dca9b4fc813e9-volumes-kubernetes.io\x7eprojected-values.mount: Deactivated successfully.1742machine # [ 36.976328] dhcpcd[585]: flannel.1: probing for an IPv4LL address1743machine # [ 36.977404] k3s[824]: I1112 11:50:23.710465 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-config" pod "fbe92022-3be2-46da-8225-ca9b4fc813e9" (UID: "fbe92022-3be2-46da-8225-ca9b4fc813e9"). InnerVolumeSpecName "klipper-config". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1744machine # [ 36.982339] k3s[824]: I1112 11:50:23.711029 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/configmap/fbe92022-3be2-46da-8225-ca9b4fc813e9-content" pod "fbe92022-3be2-46da-8225-ca9b4fc813e9" (UID: "fbe92022-3be2-46da-8225-ca9b4fc813e9"). InnerVolumeSpecName "content". PluginName "kubernetes.io/configmap", VolumeGIDValue ""1745machine # [ 36.987168] k3s[824]: I1112 11:50:23.712079 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-kube-api-access-9pj7h" pod "fbe92022-3be2-46da-8225-ca9b4fc813e9" (UID: "fbe92022-3be2-46da-8225-ca9b4fc813e9"). InnerVolumeSpecName "kube-api-access-9pj7h". PluginName "kubernetes.io/projected", VolumeGIDValue ""1746machine # [ 36.992224] k3s[824]: I1112 11:50:23.712588 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-cache" pod "fbe92022-3be2-46da-8225-ca9b4fc813e9" (UID: "fbe92022-3be2-46da-8225-ca9b4fc813e9"). InnerVolumeSpecName "klipper-cache". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1747machine # [ 36.996663] k3s[824]: I1112 11:50:23.713259 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-helm" pod "fbe92022-3be2-46da-8225-ca9b4fc813e9" (UID: "fbe92022-3be2-46da-8225-ca9b4fc813e9"). InnerVolumeSpecName "klipper-helm". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1748machine # [ 37.001261] systemd[1]: var-lib-kubelet-pods-fbe92022\x2d3be2\x2d46da\x2d8225\x2dca9b4fc813e9-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dcache.mount: Deactivated successfully.1749machine # [ 37.003527] k3s[824]: I1112 11:50:23.736799 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-tmp" pod "fbe92022-3be2-46da-8225-ca9b4fc813e9" (UID: "fbe92022-3be2-46da-8225-ca9b4fc813e9"). InnerVolumeSpecName "tmp". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1750machine # [ 37.008114] systemd[1]: var-lib-kubelet-pods-fbe92022\x2d3be2\x2d46da\x2d8225\x2dca9b4fc813e9-volumes-kubernetes.io\x7eprojected-kube\x2dapi\x2daccess\x2d9pj7h.mount: Deactivated successfully.1751machine # [ 37.010468] systemd[1]: var-lib-kubelet-pods-fbe92022\x2d3be2\x2d46da\x2d8225\x2dca9b4fc813e9-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dconfig.mount: Deactivated successfully.1752machine # [ 37.023514] k3s[824]: I1112 11:50:23.782581 824 reconciler_common.go:299] "Volume detached for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-tmp\") on node \"machine\" DevicePath \"\""1753machine # [ 37.026510] k3s[824]: I1112 11:50:23.782626 824 reconciler_common.go:299] "Volume detached for volume \"values\" (UniqueName: \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-values\") on node \"machine\" DevicePath \"\""1754machine # [ 37.029669] k3s[824]: I1112 11:50:23.782643 824 reconciler_common.go:299] "Volume detached for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-cache\") on node \"machine\" DevicePath \"\""1755machine # [ 37.033013] k3s[824]: I1112 11:50:23.782657 824 reconciler_common.go:299] "Volume detached for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-config\") on node \"machine\" DevicePath \"\""1756machine # [ 37.036865] k3s[824]: I1112 11:50:23.782670 824 reconciler_common.go:299] "Volume detached for volume \"content\" (UniqueName: \"kubernetes.io/configmap/fbe92022-3be2-46da-8225-ca9b4fc813e9-content\") on node \"machine\" DevicePath \"\""1757machine # [ 37.040062] k3s[824]: I1112 11:50:23.782686 824 reconciler_common.go:299] "Volume detached for volume \"kube-api-access-9pj7h\" (UniqueName: \"kubernetes.io/projected/fbe92022-3be2-46da-8225-ca9b4fc813e9-kube-api-access-9pj7h\") on node \"machine\" DevicePath \"\""1758machine # [ 37.043541] k3s[824]: I1112 11:50:23.782702 824 reconciler_common.go:299] "Volume detached for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/fbe92022-3be2-46da-8225-ca9b4fc813e9-klipper-helm\") on node \"machine\" DevicePath \"\""1759machine # [ 37.199043] dhcpcd[585]: veth3cfc5b83: soliciting an IPv6 router1760machine # [ 37.237198] systemd[1]: Removed slice libcontainer container kubepods-burstable-podfbe92022_3be2_46da_8225_ca9b4fc813e9.slice.1761machine # [ 37.241440] systemd[1]: kubepods-burstable-podfbe92022_3be2_46da_8225_ca9b4fc813e9.slice: Consumed 884ms CPU time over 6.380s wall clock time, 40.5M memory peak, 4.5M incoming IP traffic, 101.3K outgoing IP traffic.1762machine # [ 37.544647] k3s[824]: I1112 11:50:24.303665 824 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="cde0fbb86775d96bf64dc733f05f0a25f99b03685167900090f5e30667191bb9"1763machine # [ 37.550786] k3s[824]: E1112 11:50:24.303925 824 kubelet_pods.go:2193] "failed to read memory cgroup config for the pod" err="failed to read memory.max for cgroup /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podfbe92022_3be2_46da_8225_ca9b4fc813e9.slice: openat2 /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podfbe92022_3be2_46da_8225_ca9b4fc813e9.slice/memory.max: no such file or directory" podName="helm-install-niks3-5cxkq"1764machine # [ 37.560302] k3s[824]: E1112 11:50:24.307934 824 kubelet_pods.go:2198] "failed to read memory cgroup limits for the pod" err="failed to read cpu.max file for cgroup /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podfbe92022_3be2_46da_8225_ca9b4fc813e9.slice: openat2 /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podfbe92022_3be2_46da_8225_ca9b4fc813e9.slice/cpu.max: no such file or directory" podName="helm-install-niks3-5cxkq"1765machine # [ 37.708266] systemd[1]: var-lib-kubelet-pods-fbe92022\x2d3be2\x2d46da\x2d8225\x2dca9b4fc813e9-volumes-kubernetes.io\x7eempty\x2ddir-tmp.mount: Deactivated successfully.1766machine # [ 37.712297] systemd[1]: var-lib-kubelet-pods-fbe92022\x2d3be2\x2d46da\x2d8225\x2dca9b4fc813e9-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dhelm.mount: Deactivated successfully.1767machine # [ 40.108565] dhcpcd[585]: veth3cfc5b83: probing for an IPv4LL address1768[41.35s] machine: (finished: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s, in 15.81 seconds)1769[41.35s] machine: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true1770[41.57s] machine: (finished: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true, in 0.22 seconds)1771[41.57s] machine: waiting for success: curl -sf http://localhost:30051/readyz | grep OK1772[41.62s] machine: (finished: waiting for success: curl -sf http://localhost:30051/readyz | grep OK, in 0.04 seconds)1773[41.62s] (finished: subtest: chart deploys and becomes ready, in 16.07 seconds)1774[41.62s] machine: waiting for success: kubectl -n ci get sa builder1775[41.80s] machine: (finished: waiting for success: kubectl -n ci get sa builder, in 0.19 seconds)1776[41.80s] machine: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt1777[42.01s] machine: (finished: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt, in 0.20 seconds)1778[42.01s] machine: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt1779[42.18s] machine: (finished: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt, in 0.17 seconds)1780[42.18s] machine: must succeed: readlink -f /run/current-system/sw/bin/niks31781[42.19s] machine: (finished: must succeed: readlink -f /run/current-system/sw/bin/niks3, in 0.02 seconds)1782[42.19s] subtest: allowed service account can push via workload identity1783[42.19s] machine: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&11784machine # [ 41.899298] dhcpcd[585]: vethc6c77eca: using IPv4LL address 169.254.59.1331785machine # [ 41.900519] dhcpcd[585]: vethc6c77eca: adding route to 169.254.0.0/161786machine # [ 41.962086] dhcpcd[585]: flannel.1: using IPv4LL address 169.254.132.1301787machine # [ 41.963248] dhcpcd[585]: flannel.1: adding route to 169.254.0.0/161788[43.29s] machine: (finished: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&1, in 1.10 seconds)1789[43.29s] machine: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/an044afijna5agsc71nj88va0jbxiq27.narinfo1790[43.31s] machine: (finished: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/an044afijna5agsc71nj88va0jbxiq27.narinfo, in 0.03 seconds)1791[43.31s] (finished: subtest: allowed service account can push via workload identity, in 1.12 seconds)1792[43.31s] subtest: write scope does not grant admin1793[43.32s] machine: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status1794[43.35s] machine: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status, in 0.03 seconds)1795[43.35s] (finished: subtest: write scope does not grant admin, in 0.03 seconds)1796[43.35s] subtest: other service accounts are rejected1797[43.35s] machine: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&11798[43.48s] machine: (finished: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&1, in 0.13 seconds)1799[43.48s] (finished: subtest: other service accounts are rejected, in 0.13 seconds)1800[43.48s] subtest: gc cronjob runs against the service1801[43.48s] machine: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual1802[43.66s] machine: (finished: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual, in 0.19 seconds)1803[43.66s] machine: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s1804machine # [ 42.977326] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod8b63ffe5_8c92_424d_8404_8b368b9a1b49.slice.1805machine # [ 43.062250] k3s[824]: I1112 11:50:29.820824 824 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/8b63ffe5-8c92-424d-8404-8b368b9a1b49-token\") pod \"gc-manual-6549h\" (UID: \"8b63ffe5-8c92-424d-8404-8b368b9a1b49\") " pod="niks3/gc-manual-6549h"1806machine # [ 43.341833] (udev-worker)[1972]: Network interface NamePolicy= disabled on kernel command line.1807machine # [ 43.351249] cni0: port 1(vethfb595d96) entered blocking state1808machine # [ 43.351286] cni0: port 1(vethfb595d96) entered disabled state1809machine # [ 43.351326] vethfb595d96: entered allmulticast mode1810machine # [ 43.351483] vethfb595d96: entered promiscuous mode1811machine # [ 43.372216] cni0: port 1(vethfb595d96) entered blocking state1812machine # [ 43.372252] cni0: port 1(vethfb595d96) entered forwarding state1813machine # [ 43.398365] dhcpcd[585]: vethfb595d96: IAID 9e:54:16:2b1814machine # [ 43.401783] dhcpcd[585]: vethfb595d96: adding address fe80::5c83:9eff:fe54:162b1815machine # [ 43.480689] systemd[1]: Started libcontainer container 53d4c1e12adc90bd8b6c9b28b7fa1a217519a2043d67143cfbfeb4be5606e49a.1816machine # [ 43.604425] systemd[1]: Started libcontainer container e1451112f67955adc1a54e81befe32b343f845774f2331575c0e5933386421cc.1817machine # [ 43.684574] k3s[824]: I1112 11:50:30.443606 824 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/gc-manual-6549h" podStartSLOduration=1.4435852200000001 podStartE2EDuration="1.44358522s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 11:50:29 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 11:50:30.44159466 +0000 UTC m=+25.825621381" watchObservedRunningTime="2026-11-12 11:50:30.44358522 +0000 UTC m=+25.827611941"1818machine # [ 43.828244] dhcpcd[585]: vethfb595d96: soliciting a DHCP lease1819machine # [ 45.169502] dhcpcd[585]: flannel.1: no IPv6 Routers available1820machine # [ 45.273315] dhcpcd[585]: veth3cfc5b83: using IPv4LL address 169.254.190.2291821machine # [ 45.275212] dhcpcd[585]: veth3cfc5b83: adding route to 169.254.0.0/161822machine # [ 45.480751] dhcpcd[585]: vethc6c77eca: no IPv6 Routers available1823machine # [ 45.525776] dhcpcd[585]: vethfb595d96: soliciting an IPv6 router1824machine # [ 45.669593] systemd[1]: cri-containerd-e1451112f67955adc1a54e81befe32b343f845774f2331575c0e5933386421cc.scope: Deactivated successfully.1825machine # [ 45.672797] systemd[1]: cri-containerd-e1451112f67955adc1a54e81befe32b343f845774f2331575c0e5933386421cc.scope: Consumed 39ms CPU time over 2.064s wall clock time, 15.1M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1826machine # [ 45.731013] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-e1451112f67955adc1a54e81befe32b343f845774f2331575c0e5933386421cc-rootfs.mount: Deactivated successfully.1827machine # [ 47.607727] systemd[1]: cri-containerd-53d4c1e12adc90bd8b6c9b28b7fa1a217519a2043d67143cfbfeb4be5606e49a.scope: Deactivated successfully.1828machine # [ 47.663615] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-53d4c1e12adc90bd8b6c9b28b7fa1a217519a2043d67143cfbfeb4be5606e49a-rootfs.mount: Deactivated successfully.1829machine # [ 47.706711] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-53d4c1e12adc90bd8b6c9b28b7fa1a217519a2043d67143cfbfeb4be5606e49a-shm.mount: Deactivated successfully.1830machine # [ 47.753657] dhcpcd[585]: vethfb595d96: carrier lost1831machine # [ 47.759447] cni0: port 1(vethfb595d96) entered disabled state1832machine # [ 47.762299] vethfb595d96 (unregistering): left allmulticast mode1833machine # [ 47.762327] vethfb595d96 (unregistering): left promiscuous mode1834machine # [ 47.762341] cni0: port 1(vethfb595d96) entered disabled state1835machine # [ 47.797854] systemd[1]: run-netns-cni\x2d33ca2225\x2de3df\x2d27f0\x2dacd8\x2da7f35bb383fe.mount: Deactivated successfully.1836machine # [ 47.803670] dhcpcd[585]: vethfb595d96: deleting address fe80::5c83:9eff:fe54:162b1837machine # [ 47.860366] dhcpcd[585]: vethfb595d96: removing interface1838machine # [ 47.893360] k3s[824]: I1112 11:50:34.651634 824 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/secret/8b63ffe5-8c92-424d-8404-8b368b9a1b49-token\" (UniqueName: \"kubernetes.io/secret/8b63ffe5-8c92-424d-8404-8b368b9a1b49-token\") pod \"8b63ffe5-8c92-424d-8404-8b368b9a1b49\" (UID: \"8b63ffe5-8c92-424d-8404-8b368b9a1b49\") "1839machine # [ 47.901704] systemd[1]: var-lib-kubelet-pods-8b63ffe5\x2d8c92\x2d424d\x2d8404\x2d8b368b9a1b49-volumes-kubernetes.io\x7esecret-token.mount: Deactivated successfully.1840machine # [ 47.904650] k3s[824]: I1112 11:50:34.661774 824 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/8b63ffe5-8c92-424d-8404-8b368b9a1b49-token" pod "8b63ffe5-8c92-424d-8404-8b368b9a1b49" (UID: "8b63ffe5-8c92-424d-8404-8b368b9a1b49"). InnerVolumeSpecName "token". PluginName "kubernetes.io/secret", VolumeGIDValue ""1841machine # [ 47.993365] k3s[824]: I1112 11:50:34.752435 824 reconciler_common.go:299] "Volume detached for volume \"token\" (UniqueName: \"kubernetes.io/secret/8b63ffe5-8c92-424d-8404-8b368b9a1b49-token\") on node \"machine\" DevicePath \"\""1842machine # [ 48.411731] systemd-coredump[2410]: Process 585 (dhcpcd) of user 999 terminated abnormally with signal 11/SEGV, processing...1843machine # [ 48.419925] systemd[1]: Created slice Slice /system/systemd-coredump.1844machine # [ 48.423613] systemd[1]: Started Process Core Dump (PID 2410/UID 0).1845machine # [ 48.552567] systemd-coredump[2411]: Process 585 (dhcpcd) of user 999 dumped core.1846machine # 1847machine # Module udev.so without build-id.1848machine # Module dhcpcd without build-id.1849machine # Stack trace of thread 585:1850machine # #0 0x0000b804fccf5c94 ipv6nd_expire (dhcpcd + 0x35c94)1851machine # #1 0x0000b804fccd1b90 eloop_start (dhcpcd + 0x11b90)1852machine # #2 0x0000b804fccc9fc0 main (dhcpcd + 0x9fc0)1853machine # #3 0x0000f96c63706f74 __libc_start_call_main (libc.so.6 + 0x26f74)1854machine # #4 0x0000f96c637070b8 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x270b8)1855machine # #5 0x0000b804fcccafb0 _start (dhcpcd + 0xafb0)1856machine # ELF object binary architecture: AARCH641857machine # 1858machine # [ 48.562858] systemd[1]: systemd-coredump@0-1-2410_2411-0.service: Deactivated successfully.1859machine # [ 48.589808] k3s[824]: I1112 11:50:35.348682 824 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="53d4c1e12adc90bd8b6c9b28b7fa1a217519a2043d67143cfbfeb4be5606e49a"1860machine # [ 48.600416] systemd[1]: Removed slice libcontainer container kubepods-besteffort-pod8b63ffe5_8c92_424d_8404_8b368b9a1b49.slice.1861machine # [ 48.603166] systemd[1]: kubepods-besteffort-pod8b63ffe5_8c92_424d_8404_8b368b9a1b49.slice: Consumed 72ms CPU time over 5.623s wall clock time, 15.7M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1862[49.38s] machine: (finished: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s, in 5.71 seconds)1863[49.38s] (finished: subtest: gc cronjob runs against the service, in 5.90 seconds)1864[49.38s] subtest: helm test hook passes1865[49.38s] machine: must succeed: helm test -n niks3 niks3 --timeout 2m >&21866machine # [ 48.671875] systemd[1]: dhcpcd.service: Main process exited, code=dumped, status=11/SEGV1867machine # [ 48.677960] systemd[1]: dhcpcd.service: Failed with result 'core-dump'.1868machine # [ 48.680662] systemd[1]: dhcpcd.service: Consumed 524ms CPU time over 41.019s wall clock time, 7.2M memory peak, 8K written to disk, 96B incoming IP traffic, 784B outgoing IP traffic.1869machine # [ 48.986422] systemd[1]: dhcpcd.service: Scheduled restart job, restart counter is at 1.1870machine # [ 48.992096] systemd[1]: Starting DHCP Client...1871machine # [ 49.159794] dhcpcd[2432]: dhcpcd-10.3.2 starting1872machine # [ 49.163029] dhcpcd[2436]: dev: loaded udev1873machine # [ 49.163770] dhcpcd[2436]: DUID 00:01:00:01:32:88:64:62:52:54:00:12:34:561874machine # [ 49.211022] systemd[1]: Created slice libcontainer container kubepods-besteffort-podcae7c574_2d3e_4e5b_8c47_fa52d4edf120.slice.1875machine # [ 49.244941] dhcpcd[2436]: eth0: IAID 00:12:34:561876machine # [ 49.247241] dhcpcd[2436]: flannel.1: IAID 7d:e1:3d:a81877machine # [ 49.248119] dhcpcd[2436]: vethc6c77eca: IAID f6:12:5a:e51878machine # [ 49.248938] dhcpcd[2436]: veth3cfc5b83: IAID f7:0e:91:881879machine # [ 49.274663] (udev-worker)[2376]: Network interface NamePolicy= disabled on kernel command line.1880machine # [ 49.280430] cni0: port 1(veth24d020db) entered blocking state1881machine # [ 49.280462] cni0: port 1(veth24d020db) entered disabled state1882machine # [ 49.280492] veth24d020db: entered allmulticast mode1883machine # [ 49.280609] veth24d020db: entered promiscuous mode1884machine # [ 49.299162] cni0: port 1(veth24d020db) entered blocking state1885machine # [ 49.299189] cni0: port 1(veth24d020db) entered forwarding state1886machine # [ 49.319263] dhcpcd[2436]: veth24d020db: IAID e5:12:ef:ad1887machine # [ 49.320713] dhcpcd[2436]: veth24d020db: adding address fe80::a0f5:e5ff:fe12:efad1888machine # [ 49.337553] dhcpcd[2436]: flannel.1: soliciting a DHCP lease1889machine # [ 49.348399] dhcpcd[2436]: veth3cfc5b83: soliciting a DHCP lease1890machine # [ 49.420566] systemd[1]: Started libcontainer container fe5e74c58da9621c9981e6dbafce4761813e106f507ed76cdc4f1b60d21415ac.1891machine # [ 49.572546] systemd[1]: Started libcontainer container f49bfb5a52dc072a871e042ddb1c04504f980bef579667f173be54603b5c84b1.1892machine # [ 49.631564] systemd[1]: cri-containerd-f49bfb5a52dc072a871e042ddb1c04504f980bef579667f173be54603b5c84b1.scope: Deactivated successfully.1893machine # [ 49.634905] systemd[1]: cri-containerd-f49bfb5a52dc072a871e042ddb1c04504f980bef579667f173be54603b5c84b1.scope: Consumed 31ms CPU time over 61ms wall clock time, 15.1M memory peak, 641B incoming IP traffic, 547B outgoing IP traffic.1894machine # [ 49.661478] k3s[824]: I1112 11:50:36.419042 824 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-test" podStartSLOduration=1.4190215400000001 podStartE2EDuration="1.41902154s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 11:50:35 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 11:50:36.41647026 +0000 UTC m=+31.800496981" watchObservedRunningTime="2026-11-12 11:50:36.41902154 +0000 UTC m=+31.803048261"1895machine # [ 49.691232] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-f49bfb5a52dc072a871e042ddb1c04504f980bef579667f173be54603b5c84b1-rootfs.mount: Deactivated successfully.1896machine # [ 49.926277] dhcpcd[2436]: vethc6c77eca: soliciting an IPv6 router1897machine # [ 50.096643] dhcpcd[2436]: veth3cfc5b83: soliciting an IPv6 router1898machine # [ 50.174090] dhcpcd[2436]: veth24d020db: soliciting a DHCP lease1899machine # [ 50.192629] dhcpcd[2436]: eth0: soliciting an IPv6 router1900machine # [ 50.194146] dhcpcd[2436]: eth0: Router Advertisement from fe80::21901machine # [ 50.195552] dhcpcd[2436]: eth0: adding address fec0::5054:ff:fe12:3456/641902machine # [ 50.229595] dhcpcd[2436]: flannel.1: soliciting an IPv6 router1903machine # [ 50.269012] dhcpcd[2436]: vethc6c77eca: soliciting a DHCP lease1904machine # [ 50.491015] dhcpcd[2436]: eth0: rebinding lease of 10.0.2.151905machine # [ 50.504574] dhcpcd[2436]: eth0: leased 10.0.2.15 for 86400 seconds1906machine # [ 50.549505] systemd[1]: Started DHCP Client.1907machine # [ 51.624740] systemd[1]: cri-containerd-fe5e74c58da9621c9981e6dbafce4761813e106f507ed76cdc4f1b60d21415ac.scope: Deactivated successfully.1908machine # [ 51.674688] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-fe5e74c58da9621c9981e6dbafce4761813e106f507ed76cdc4f1b60d21415ac-rootfs.mount: Deactivated successfully.1909machine # [ 51.709889] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-fe5e74c58da9621c9981e6dbafce4761813e106f507ed76cdc4f1b60d21415ac-shm.mount: Deactivated successfully.1910machine # [ 51.715380] dhcpcd[2436]: veth24d020db: soliciting an IPv6 router1911machine # [ 51.757975] dhcpcd[2436]: veth24d020db: carrier lost1912machine # [ 51.764054] cni0: port 1(veth24d020db) entered disabled state1913machine # [ 51.765510] veth24d020db (unregistering): left allmulticast mode1914machine # [ 51.765551] veth24d020db (unregistering): left promiscuous mode1915machine # [ 51.765566] cni0: port 1(veth24d020db) entered disabled state1916machine # [ 51.795193] systemd[1]: run-netns-cni\x2d6327933c\x2de21a\x2d5bd7\x2dda7a\x2de316c774ab8d.mount: Deactivated successfully.1917machine # [ 51.828984] dhcpcd[2436]: veth24d020db: deleting address fe80::a0f5:e5ff:fe12:efad1918machine # NAME: niks31919machine # LAST DEPLOYED: Thu Nov 12 11:50:20 20261920machine # NAMESPACE: niks31921machine # STATUS: deployed1922machine # REVISION: 11923machine # DESCRIPTION: Install complete1924machine # TEST SUITE: niks3-test1925machine # Last Started: Thu Nov 12 11:50:35 20261926machine # Last Completed: Thu Nov 12 11:50:38 20261927machine # Phase: Succeeded1928[52.60s] machine: (finished: must succeed: helm test -n niks3 niks3 --timeout 2m >&2, in 3.23 seconds)1929[52.60s] (finished: subtest: helm test hook passes, in 3.23 seconds)1930[52.60s] (finished: run the VM test script, in 52.60 seconds)1931machine # [ 51.900376] dhcpcd[2436]: veth24d020db: removing interface1932[52.65s] test script finished in 52.64s1933[52.65s] cleanup1934[52.65s] kill QemuMachine (pid 45)1935machine # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/lq2fsnmg0q3y0vlxn91w8s8wvj1m6fld-python3-3.14.8/bin/python3.14)1936machine # [2026-11-12T11:50:38Z INFO virtiofsd] Client disconnected, shutting down1937machine # [2026-11-12T11:50:38Z INFO virtiofsd] Client disconnected, shutting down1938machine # [2026-11-12T11:50:38Z INFO virtiofsd] Client disconnected, shutting down1939[53.55s] (finished: cleanup, in 0.90 seconds)1940additionally exposed symbols:1941 machine,1942 vlan1,1943 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_ssh1944time=2026-11-12T11:50:28.408Z level=INFO msg="Uploading 8 paths to localhost (0 already cached)"1945time=2026-11-12T11:50:28.408Z level=INFO msg="Uploading nhphqkv18x8fpf3flz0bsm1h554pawn7-glibc-2.44-57 (44.8MB)"1946time=2026-11-12T11:50:28.408Z level=INFO msg="Uploading vr8lx1cjz6zw4xhmb4k405v6cqrkslnk-libunistring-1.4.2 (2.0MB)"1947time=2026-11-12T11:50:28.408Z level=INFO msg="Uploading an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 (7.2MB)"1948time=2026-11-12T11:50:28.410Z level=INFO msg="Uploading wsn07qxxn13gcdcjw5avz47j8lb2zpdv-libidn2-2.3.8 (366.1KB)"1949time=2026-11-12T11:50:28.410Z level=INFO msg="Uploading ad9h5b41f7x4fvk22axfjvxykisyjc15-tzdata-2026e (2.0MB)"1950time=2026-11-12T11:50:28.411Z level=INFO msg="Uploading 7kfrkscfmm8p09q9w392p86rxqji8cbf-mailcap-2.1.54 (116.6KB)"1951time=2026-11-12T11:50:28.411Z level=INFO msg="Uploading 09mqjwlgdr2jchjchwpgff2vryn4zc4q-xgcc-16.2.0-libgcc (150.2KB)"1952time=2026-11-12T11:50:28.412Z level=INFO msg="Uploading a9l8h2d532wk9zpyvl3qms0v5iwbjp67-iana-etc-20251215 (557.8KB)"1953time=2026-11-12T11:50:29.270Z level=INFO msg="Uploading 8 narinfos"1954time=2026-11-12T11:50:29.320Z level=INFO msg="Upload complete. (1.001s)"1955