vm-test-run-nixos-test-k3s
checks.aarch64-linux.nixos-test-k3s
· build #161
· raw
1tribuchet: building on eliza2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Test will time out and terminate in 3600.0 seconds6run the VM test script7machine: waiting for unit k3s.service8machine: waiting for the VM to finish booting9machine: starting vm10machine # Disk image does not exist, creating the virtualisation disk image...11machine: QEMU running (pid 45)12machine # Formatting '/build/vm-state-machine/tmp.C2u34YsoB2', 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: 73be49f4-bbc5-4503-80be-679168e753e917machine # 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 # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]27machine # [ 0.000000] Linux version 6.18.44 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Sun Aug 9 18:25:30 UTC 202628machine # [ 0.000000] KASLR enabled29machine # [ 0.000000] random: crng init done30machine # [ 0.000000] Machine model: linux,dummy-virt31machine # [ 0.000000] efi: UEFI not found.32machine # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT33machine # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000ffffffff]34machine # [ 0.000000] NODE_DATA(0) allocated [mem 0xffdec1c0-0xffdef93f]35machine # [ 0.000000] Zone ranges:36machine # [ 0.000000] DMA [mem 0x0000000040000000-0x00000000ffffffff]37machine # [ 0.000000] DMA32 empty38machine # [ 0.000000] Normal empty39machine # [ 0.000000] Device empty40machine # [ 0.000000] Movable zone start for each node41machine # [ 0.000000] Early memory node ranges42machine # [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000ffffffff]43machine # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x00000000ffffffff]44machine # [ 0.000000] cma: Reserved 32 MiB at 0x00000000fac0000045machine # [ 0.000000] psci: probing for conduit method from DT.46machine # [ 0.000000] psci: PSCIv1.3 detected in firmware.47machine # [ 0.000000] psci: Using standard PSCI v0.2 function IDs48machine # [ 0.000000] psci: Trusted OS migration not required49machine # [ 0.000000] psci: SMC Calling Convention v1.150machine # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)51machine # [ 0.000000] percpu: Embedded 76 pages/cpu s186712 r8192 d116392 u31129652machine # [ 0.000000] Detected PIPT I-cache on CPU053machine # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)54machine # [ 0.000000] CPU features: detected: GICv3 CPU interface55machine # [ 0.000000] CPU features: detected: Spectre-v456machine # [ 0.000000] CPU features: detected: Spectre-BHB57machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_3858machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_2359machine # [ 0.000000] alternatives: applying boot alternatives60machine # [ 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/iwslnprwa8kiyh0cr3n6xw3nrp6w6ck7-nixos-system-machine-test/init regInfo=/nix/store/969l8n481y38j4dmab0la9a7rnphfp42-closure-info/registration console=ttyAMA0,115200n8 console=tty061machine # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/store/969l8n481y38j4dmab0la9a7rnphfp42-closure-info/registration", will be passed to user space.62machine # [ 0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes63machine # [ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)64machine # [ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)65machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 3MB66machine # [ 0.000000] software IO TLB: area num 2.67machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size roundup to 4MB68machine # [ 0.000000] software IO TLB: mapped [mem 0x00000000fa200000-0x00000000fa600000] (4MB)69machine # [ 0.000000] Fallback order for Node 0: 070machine # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 78643271machine # [ 0.000000] Policy zone: DMA72machine # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off73machine # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=174machine # [ 0.000000] allocated 6291456 bytes of page_ext75machine # [ 0.000000] ftrace: allocating 74867 entries in 294 pages76machine # [ 0.000000] ftrace: allocated 294 pages with 4 groups77machine # [ 0.000000] rcu: Hierarchical RCU implementation.78machine # [ 0.000000] rcu: RCU event tracing is enabled.79machine # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=2.80machine # [ 0.000000] Trampoline variant of Tasks RCU enabled.81machine # [ 0.000000] Rude variant of Tasks RCU enabled.82machine # [ 0.000000] Tracing variant of Tasks RCU enabled.83machine # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.84machine # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=285machine # [ 0.000000] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.86machine # [ 0.000000] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.87machine # [ 0.000000] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.88machine # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 089machine # [ 0.000000] GICv3: 256 SPIs implemented90machine # [ 0.000000] GICv3: 0 Extended SPIs implemented91machine # [ 0.000000] Root IRQ handler: gic_handle_irq92machine # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI93machine # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=094machine # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a000095machine # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]96machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @45110000 (indirect, esz 8, psz 64K, shr 1)97machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @45120000 (flat, esz 8, psz 64K, shr 1)98machine # [ 0.000000] GICv3: using LPI property table @0x000000004513000099machine # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000045140000100machine # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.101machine # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns102machine # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).103machine # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns104machine # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns105machine # [ 0.000037] arm-pv: using stolen time PV106machine # [ 0.000387] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)107machine # [ 0.000566] Console: colour dummy device 80x25108machine # [ 0.000573] printk: legacy console [tty0] enabled109machine # [ 0.000763] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)110machine # [ 0.000769] pid_max: default: 32768 minimum: 301111machine # [ 0.000843] LSM: initializing lsm=capability,landlock,yama,bpf,ima112machine # [ 0.001011] landlock: Up and running.113machine # [ 0.001014] Yama: becoming mindful.114machine # [ 0.001429] LSM support for eBPF active115machine # [ 0.001576] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)116machine # [ 0.001630] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)117machine # [ 0.002740] cacheinfo: Unable to detect cache hierarchy for CPU 0118machine # [ 0.003523] rcu: Hierarchical SRCU implementation.119machine # [ 0.003527] rcu: Max phase no-delay instances is 1000.120machine # [ 0.003680] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level121machine # [ 0.004754] fsl-mc MSI: its@8080000 domain created122machine # [ 0.004846] EFI services will not be available.123machine # [ 0.004946] smp: Bringing up secondary CPUs ...124machine # [ 0.005639] Detected PIPT I-cache on CPU1125machine # [ 0.005747] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000126machine # [ 0.005877] GICv3: CPU1: using allocated LPI pending table @0x0000000045150000127machine # [ 0.006005] CPU1: Booted secondary processor 0x0000000001 [0xc00fac40]128machine # [ 0.006589] smp: Brought up 1 node, 2 CPUs129machine # [ 0.006603] SMP: Total of 2 processors activated.130machine # [ 0.006606] CPU: All CPU(s) started at EL1131machine # [ 0.006615] CPU features: detected: Branch Target Identification132machine # [ 0.006619] CPU features: detected: ARMv8.4 Translation Table Level133machine # [ 0.006622] CPU features: detected: Instruction cache invalidation not required for I/D coherence134machine # [ 0.006625] CPU features: detected: Data cache clean to the PoU not required for I/D coherence135machine # [ 0.006629] CPU features: detected: Common not Private translations136machine # [ 0.006632] CPU features: detected: CRC32 instructions137machine # [ 0.006634] CPU features: detected: Data cache clean to Point of Deep Persistence138machine # [ 0.006638] CPU features: detected: Data cache clean to Point of Persistence139machine # [ 0.006641] CPU features: detected: Data independent timing control (DIT)140machine # [ 0.006643] CPU features: detected: E0PD141machine # [ 0.006646] CPU features: detected: Enhanced Counter Virtualization142machine # [ 0.006648] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)143machine # [ 0.006651] CPU features: detected: Enhanced Virtualization Traps144machine # [ 0.006654] CPU features: detected: Fine Grained Traps145machine # [ 0.006657] CPU features: detected: Generic authentication (architected QARMA5 algorithm)146machine # [ 0.006661] CPU features: detected: RCpc load-acquire (LDAPR)147machine # [ 0.006664] CPU features: detected: LSE atomic instructions148machine # [ 0.006666] CPU features: detected: Privileged Access Never149machine # [ 0.006669] CPU features: detected: PMUv3150machine # [ 0.006671] CPU features: detected: RAS Extension Support151machine # [ 0.006674] CPU features: detected: RASv1p1 Extension Support152machine # [ 0.006677] CPU features: detected: Random Number Generator153machine # [ 0.006679] CPU features: detected: Speculation barrier (SB)154machine # [ 0.006681] CPU features: detected: Stage-2 Force Write-Back155machine # [ 0.006684] CPU features: detected: TLB range maintenance instructions156machine # [ 0.006688] CPU features: detected: Speculative Store Bypassing Safe (SSBS)157machine # [ 0.006812] alternatives: applying system-wide alternatives158machine # [ 0.009711] CPU features: detected: BBM Level 2 without TLB conflict abort159machine # [ 0.009951] Memory: 2944248K/3145728K available (24448K kernel code, 7090K rwdata, 26344K rodata, 4736K init, 1107K bss, 154796K reserved, 32768K cma-reserved)160machine # [ 0.011443] devtmpfs: initialized161machine # [ 0.014353] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)162machine # [ 0.014397] futex hash table entries: 512 (32768 bytes on 1 NUMA nodes, total 32 KiB, linear).163machine # [ 0.014606] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL164machine # [ 0.014611] 0 pages in range for non-PLT usage165machine # [ 0.014612] 508288 pages in range for PLT usage166machine # [ 0.014742] pinctrl core: initialized pinctrl subsystem167machine # [ 0.015661] DMI not present or invalid.168machine # [ 0.019230] NET: Registered PF_NETLINK/PF_ROUTE protocol family169machine # [ 0.021571] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations170machine # [ 0.021882] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations171machine # [ 0.022225] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations172machine # [ 0.022253] audit: initializing netlink subsys (disabled)173machine # [ 0.023004] audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1174machine # [ 0.025417] thermal_sys: Registered thermal governor 'fair_share'175machine # [ 0.025427] thermal_sys: Registered thermal governor 'bang_bang'176machine # [ 0.025442] thermal_sys: Registered thermal governor 'step_wise'177machine # [ 0.025450] thermal_sys: Registered thermal governor 'user_space'178machine # [ 0.025458] thermal_sys: Registered thermal governor 'power_allocator'179machine # [ 0.025596] cpuidle: using governor ladder180machine # [ 0.025664] cpuidle: using governor menu181machine # [ 0.026566] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.182machine # [ 0.026657] ASID allocator initialised with 65536 entries183machine # [ 0.031207] Serial: AMBA PL011 UART driver184machine # [ 0.049597] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1185machine # [ 0.050198] printk: console [ttyAMA0] enabled186machine # [ 0.077867] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages187machine # [ 0.077878] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page188machine # [ 0.077885] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages189machine # [ 0.077891] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page190machine # [ 0.077897] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages191machine # [ 0.077903] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page192machine # [ 0.077909] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages193machine # [ 0.077915] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page194machine # [ 0.099074] fbcon: Taking over console195machine # [ 0.099098] ACPI: Interpreter disabled.196machine # [ 0.100952] iommu: Default domain type: Translated197machine # [ 0.100958] iommu: DMA domain TLB invalidation policy: strict mode198machine # [ 0.102214] SCSI subsystem initialized199machine # [ 0.102814] usbcore: registered new interface driver usbfs200machine # [ 0.102860] usbcore: registered new interface driver hub201machine # [ 0.102895] usbcore: registered new device driver usb202machine # [ 0.103443] pps_core: LinuxPPS API ver. 1 registered203machine # [ 0.103447] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>204machine # [ 0.103461] PTP clock support registered205machine # [ 0.103530] EDAC MC: Ver: 3.0.0206machine # [ 0.110668] scmi_core: SCMI protocol bus registered207machine # [ 0.115036] FPGA manager framework208machine # [ 0.116288] vgaarb: loaded209machine # [ 0.119183] clocksource: Switched to clocksource arch_sys_counter210machine # [ 0.120233] VFS: Disk quotas dquot_6.6.0211machine # [ 0.120275] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)212machine # [ 0.123932] netfs: FS-Cache loaded213machine # [ 0.124129] pnp: PnP ACPI: disabled214machine # [ 0.129166] NET: Registered PF_INET protocol family215machine # [ 0.129863] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)216machine # [ 0.165515] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)217machine # [ 0.165580] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)218machine # [ 0.165649] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)219machine # [ 0.165943] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)220machine # [ 0.166315] TCP: Hash tables configured (established 32768 bind 32768)221machine # [ 0.166473] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear)222machine # [ 0.166546] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)223machine # [ 0.166636] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)224machine # [ 0.166859] NET: Registered PF_UNIX/PF_LOCAL protocol family225machine # [ 0.166886] NET: Registered PF_XDP protocol family226machine # [ 0.166914] PCI: CLS 0 bytes, default 64227machine # [ 0.167306] Trying to unpack rootfs image as initramfs...228machine # [ 0.179757] kvm [1]: HYP mode not available229machine # [ 0.308737] Initialise system trusted keyrings230machine # [ 0.308977] workingset: timestamp_bits=42 max_order=20 bucket_order=0231machine # [ 0.309762] squashfs: version 4.0 (2009/01/31) Phillip Lougher232machine # [ 0.309889] 9p: Installing v9fs 9p2000 file system support233machine # [ 0.322021] Key type asymmetric registered234machine # [ 0.322044] Asymmetric key parser 'x509' registered235machine # [ 0.322136] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)236machine # [ 0.322287] io scheduler mq-deadline registered237machine # [ 0.322300] io scheduler kyber registered238machine # [ 0.331354] pl061_gpio 9030000.pl061: PL061 GPIO chip registered239machine # [ 0.335294] ledtrig-cpu: registered to indicate activity on CPUs240machine # [ 0.335766] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:241machine # [ 0.335793] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000242machine # [ 0.335809] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000243machine # [ 0.335817] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000244machine # [ 0.335846] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits245machine # [ 0.335877] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]246machine # [ 0.336004] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00247machine # [ 0.336016] pci_bus 0000:00: root bus resource [bus 00-ff]248machine # [ 0.336023] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]249machine # [ 0.336029] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]250machine # [ 0.336035] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]251machine # [ 0.336134] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint252machine # [ 0.336592] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint253machine # [ 0.336780] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]254machine # [ 0.336797] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]255machine # [ 0.336828] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]256machine # [ 0.336845] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]257machine # [ 0.337296] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint258machine # [ 0.337481] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]259machine # [ 0.337498] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]260machine # [ 0.337528] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]261machine # [ 0.337999] pci 0000:00:03.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint262machine # [ 0.338190] pci 0000:00:03.0: BAR 0 [io 0x0000-0x003f]263machine # [ 0.338207] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]264machine # [ 0.338240] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]265machine # [ 0.338692] pci 0000:00:04.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint266machine # [ 0.338873] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]267machine # [ 0.338889] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]268machine # [ 0.338920] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]269machine # [ 0.365213] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint270machine # [ 0.365399] pci 0000:00:05.0: BAR 0 [io 0x0000-0x001f]271machine # [ 0.365415] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]272machine # [ 0.365445] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]273machine # [ 0.365892] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint274machine # [ 0.366083] pci 0000:00:06.0: BAR 0 [io 0x0000-0x007f]275machine # [ 0.366100] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]276machine # [ 0.366129] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]277machine # [ 0.366599] pci 0000:00:07.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint278machine # [ 0.366781] pci 0000:00:07.0: BAR 0 [io 0x0000-0x001f]279machine # [ 0.366797] pci 0000:00:07.0: BAR 1 [mem 0x00000000-0x00000fff]280machine # [ 0.366827] pci 0000:00:07.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]281machine # [ 0.366844] pci 0000:00:07.0: ROM [mem 0x00000000-0x0003ffff pref]282machine # [ 0.377698] pci 0000:00:08.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint283machine # [ 0.377887] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]284machine # [ 0.377917] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]285machine # [ 0.378383] pci 0000:00:09.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint286machine # [ 0.378569] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]287machine # [ 0.378599] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]288machine # [ 0.378986] pci 0000:00:0a.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint289machine # [ 0.379166] pci 0000:00:0a.0: BAR 0 [mem 0x00000000-0x00000fff]290machine # [ 0.386388] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint291machine # [ 0.386697] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]292machine # [ 0.386717] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]293machine # [ 0.386750] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]294machine # [ 0.390633] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint295machine # [ 0.390833] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]296machine # [ 0.390851] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]297machine # [ 0.390883] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]298machine # [ 0.394763] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned299machine # [ 0.394780] pci 0000:00:07.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned300machine # [ 0.394787] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned301machine # [ 0.394834] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned302machine # [ 0.394884] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned303machine # [ 0.394935] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned304machine # [ 0.394985] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned305machine # [ 0.395033] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned306machine # [ 0.395083] pci 0000:00:07.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned307machine # [ 0.395137] pci 0000:00:08.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned308machine # [ 0.403253] pci 0000:00:09.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned309machine # [ 0.403387] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned310machine # [ 0.403497] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned311machine # [ 0.403550] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned312machine # [ 0.403571] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned313machine # [ 0.403590] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned314machine # [ 0.403610] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned315machine # [ 0.403630] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned316machine # [ 0.403655] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned317machine # [ 0.403676] pci 0000:00:07.0: BAR 1 [mem 0x10086000-0x10086fff]: assigned318machine # [ 0.403696] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned319machine # [ 0.403729] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned320machine # [ 0.403749] pci 0000:00:0a.0: BAR 0 [mem 0x10089000-0x10089fff]: assigned321machine # [ 0.403770] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned322machine # [ 0.403797] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned323machine # [ 0.403816] pci 0000:00:06.0: BAR 0 [io 0x1000-0x107f]: assigned324machine # [ 0.403840] pci 0000:00:03.0: BAR 0 [io 0x1080-0x10bf]: assigned325machine # [ 0.403859] pci 0000:00:0b.0: BAR 0 [io 0x10c0-0x10ff]: assigned326machine # [ 0.403878] pci 0000:00:01.0: BAR 0 [io 0x1100-0x111f]: assigned327machine # [ 0.403901] pci 0000:00:02.0: BAR 0 [io 0x1120-0x113f]: assigned328machine # [ 0.403921] pci 0000:00:04.0: BAR 0 [io 0x1140-0x115f]: assigned329machine # [ 0.403940] pci 0000:00:05.0: BAR 0 [io 0x1160-0x117f]: assigned330machine # [ 0.403960] pci 0000:00:07.0: BAR 0 [io 0x1180-0x119f]: assigned331machine # [ 0.403980] pci 0000:00:0c.0: BAR 0 [io 0x11a0-0x11bf]: assigned332machine # [ 0.404010] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]333machine # [ 0.404015] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]334machine # [ 0.404018] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]335machine # [ 0.405568] pci 0000:00:0a.0: enabling device (0000 -> 0002)336machine # [ 0.439229] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)337machine # [ 0.441947] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)338machine # [ 0.444375] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)339machine # [ 0.446727] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)340machine # [ 0.449163] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)341machine # [ 0.453684] virtio-pci 0000:00:06.0: enabling device (0000 -> 0003)342machine # [ 0.456320] virtio-pci 0000:00:07.0: enabling device (0000 -> 0003)343machine # [ 0.458658] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)344machine # [ 0.461175] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)345machine # [ 0.465143] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)346machine # [ 0.468604] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)347machine # [ 0.476567] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled348machine # [ 0.479806] msm_serial: driver initialized349machine # [ 0.480081] SuperH (H)SCI(F) driver initialized350machine # [ 0.480172] STM32 USART driver initialized351machine # [ 0.505369] loop: module loaded352machine # [ 0.505643] virtio_blk virtio5: 2/0/0 default/read/poll queues353machine # [ 0.507437] virtio_blk virtio5: [vda] 16777216 512-byte logical blocks (8.59 GB/8.00 GiB)354machine # [ 0.512309] megasas: 07.734.00.00-rc1355machine # [ 0.513244] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]356machine # [ 0.515874] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000357machine # [ 0.515976] Intel/Sharp Extended Query Table at 0x0031358machine # [ 0.517894] Using buffer write method359machine # [ 0.517952] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]360machine # [ 0.526193] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000361machine # [ 0.526228] Intel/Sharp Extended Query Table at 0x0031362machine # [ 0.529620] Using buffer write method363machine # [ 0.529656] Concatenating MTD devices:364machine # [ 0.529661] (0): "0.flash"365machine # [ 0.529666] (1): "0.flash"366machine # [ 0.529671] into device "0.flash"367machine # [ 0.728288] Freeing initrd memory: 27144K368machine # [ 0.736736] tun: Universal TUN/TAP device driver, 1.6369machine # [ 0.741259] thunder_xcv, ver 1.0370machine # [ 0.741319] thunder_bgx, ver 1.0371machine # [ 0.741343] nicpf, ver 1.0372machine # [ 0.741977] e1000: Intel(R) PRO/1000 Network Driver373machine # [ 0.741982] e1000: Copyright (c) 1999-2006 Intel Corporation.374machine # [ 0.742005] e1000e: Intel(R) PRO/1000 Network Driver375machine # [ 0.742010] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.376machine # [ 0.742053] igb: Intel(R) Gigabit Ethernet Network Driver377machine # [ 0.742056] igb: Copyright (c) 2007-2014 Intel Corporation.378machine # [ 0.742079] igbvf: Intel(R) Gigabit Virtual Function Network Driver379machine # [ 0.742083] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.380machine # [ 0.742227] sky2: driver version 1.30381machine # [ 0.743965] usbcore: registered new interface driver usb-storage382machine # [ 0.744098] usbcore: registered new interface driver usbserial_generic383machine # [ 0.744113] usbserial: USB Serial support registered for generic384machine # [ 0.744706] hv_vmbus: registering driver hyperv_keyboard385machine # [ 0.745701] rtc-pl031 9010000.pl031: registered as rtc0386machine # [ 0.745728] rtc-pl031 9010000.pl031: setting system clock to 2026-08-27T17:07:24 UTC (1787850444)387machine # [ 0.746117] i2c_dev: i2c /dev entries driver388machine # [ 0.748845] sdhci: Secure Digital Host Controller Interface driver389machine # [ 0.748851] sdhci: Copyright(c) Pierre Ossman390machine # [ 0.749113] Synopsys Designware Multimedia Card Interface Driver391machine # [ 0.749490] sdhci-pltfm: SDHCI platform and OF driver helper392machine # [ 0.750863] ehci-pci 0000:00:0a.0: EHCI Host Controller393machine # [ 0.750920] ehci-pci 0000:00:0a.0: new USB bus registered, assigned bus number 1394machine # [ 0.751248] hid: raw HID events driver (C) Jiri Kosina395machine # [ 0.751530] usbcore: registered new interface driver usbhid396machine # [ 0.751533] usbhid: USB HID core driver397machine # [ 0.751557] ehci-pci 0000:00:0a.0: irq 15, io mem 0x10089000398machine # [ 0.756213] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available399machine # [ 0.757801] drop_monitor: Initializing network drop monitor service400machine # [ 0.757957] NET: Registered PF_INET6 protocol family401machine # [ 0.758611] Segment Routing with IPv6402machine # [ 0.758629] In-situ OAM (IOAM) with IPv6403machine # [ 0.758655] NET: Registered PF_PACKET protocol family404machine # [ 0.759271] 9pnet: Installing 9P2000 support405machine # [ 0.761678] Key type dns_resolver registered406machine # [ 0.767578] registered taskstats version 1407machine # [ 0.767726] Loading compiled-in X.509 certificates408machine # [ 0.775223] ehci-pci 0000:00:0a.0: USB 2.0 started, EHCI 1.00409machine # [ 0.775546] hub 1-0:1.0: USB hub found410machine # [ 0.775605] hub 1-0:1.0: 6 ports detected411machine # [ 0.776612] Demotion targets for Node 0: null412machine # [ 0.776804] Key type .fscrypt registered413machine # [ 0.776808] Key type fscrypt-provisioning registered414machine # [ 0.776913] ima: No TPM chip found, activating TPM-bypass!415machine # [ 0.776931] ima: Allocated hash algorithm: sha1416machine # [ 0.776949] ima: No architecture policies found417machine # [ 0.777611] input: gpio-keys as /devices/platform/gpio-keys/input/input0418machine # [ 0.805866] clk: Disabling unused clocks419machine # [ 0.805884] PM: genpd: Disabling unused power domains420machine # [ 0.810445] Freeing unused kernel memory: 4736K421machine # [ 0.810637] Run /init as init process422machine # [ 0.849282] systemd[1]: Successfully made /usr/ read-only.423machine # [ 1.023466] usb 1-1: new high-speed USB device number 2 using ehci-pci424machine # [ 1.178437] input: QEMU QEMU USB Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:0a.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input1425machine # [ 1.185888] systemd[1]: systemd 261.1 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)426machine # [ 1.186029] systemd[1]: Detected virtualization qemu.427machine # [ 1.186225] systemd[1]: Detected architecture arm64.428machine # [ 1.186310] systemd[1]: Running in initrd.429machine # [ 1.188656] systemd[1]: Initializing machine ID from random generator.430machine # [ 1.189296] systemd[1]: Hostname set to <machine>.431machine # [ 1.276691] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:0a.0-1/input0432machine # [ 1.395345] usb 1-2: new high-speed USB device number 3 using ehci-pci433machine # [ 1.540832] systemd[1]: bpf-restrict-fs: LSM BPF program attached434machine # [ 1.565224] input: QEMU QEMU USB Tablet as /devices/platform/4010000000.pcie/pci0000:00/0000:00:0a.0/usb1/1-2/1-2:1.0/0003:0627:0001.0002/input/input2435machine # [ 1.568380] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:0a.0-2/input0436machine # [ 1.688339] systemd[1]: Queued start job for default target Initrd Default Target.437machine # [ 1.710929] systemd[1]: Created slice Slice /system/modprobe.438machine # [ 1.712112] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.439machine # [ 1.712298] systemd[1]: Expecting device /dev/disk/by-label/nixos...440machine # [ 1.712487] systemd[1]: Reached target Path Units.441machine # [ 1.712651] systemd[1]: Reached target Slice Units.442machine # [ 1.712865] systemd[1]: Reached target Swaps.443machine # [ 1.712995] systemd[1]: Reached target Timer Units.444machine # [ 1.713684] systemd[1]: Listening on D-Bus System Message Bus Socket.445machine # [ 1.714510] systemd[1]: Listening on Journal Socket (/dev/log).446machine # [ 1.715322] systemd[1]: Listening on Journal Sockets.447machine # [ 1.716045] systemd[1]: Listening on udev Control Socket.448machine # [ 1.716620] systemd[1]: Listening on udev Kernel Socket.449machine # [ 1.716791] systemd[1]: Reached target Socket Units.450machine # [ 1.723638] systemd[1]: Starting Create List of Static Device Nodes...451machine # [ 1.731553] systemd[1]: Starting Load Kernel Module 9pnet_virtio...452machine # [ 1.731767] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs453machine # [ 1.743522] systemd[1]: Mounting Kernel Configuration File System...454machine # [ 1.787809] systemd[1]: Starting Journal Service...455machine # [ 1.816850] systemd[1]: Starting Load Kernel Modules...456machine # [ 1.818560] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os457machine # [ 1.829054] systemd[1]: Starting Coldplug All udev Devices...458machine # [ 1.851759] systemd[1]: Finished Create List of Static Device Nodes.459machine # [ 1.860536] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.460machine # [ 1.863017] systemd[1]: Finished Load Kernel Module 9pnet_virtio.461machine # [ 1.865203] systemd[1]: Mounted Kernel Configuration File System.462machine # [ 1.879583] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...463machine # [ 1.906108] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.464machine # [ 1.910856] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev465machine # [ 1.923300] [drm] pci: virtio-gpu-pci detected at 0000:00:08.0466machine # [ 1.923698] [drm] features: -virgl +edid -resource_blob -host_visible467machine # [ 1.923703] [drm] features: -context_init468machine # [ 1.924857] [drm] number of scanouts: 1469machine # [ 1.924874] [drm] number of cap sets: 0470machine # [ 1.926359] systemd-journald[81]: Collecting audit messages is disabled.471machine # [ 1.939808] virtio-pci 0000:00:08.0: [drm] Registered 1 planes with drm panic472machine # [ 1.939842] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:08.0 on minor 0473machine # [ 1.943525] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.474machine # [ 1.955883] systemd[1]: Starting Create Static Device Nodes in /dev...475machine # [ 1.977026] Console: switching to colour frame buffer device 160x50476machine # [ 2.004939] virtio-pci 0000:00:08.0: [drm] fb0: virtio_gpudrmfb frame buffer device477machine # [ 2.020347] systemd[1]: Finished Create Static Device Nodes in /dev.478machine # [ 2.020890] systemd[1]: Reached target Preparation for Local File Systems.479machine # [ 2.022799] systemd[1]: Reached target Local File Systems.480machine # [ 2.039776] systemd[1]: Starting Rule-based Manager for Device Events and Files...481machine # [ 2.040905] systemd[1]: Finished Load Kernel Modules.482machine # [ 2.047995] systemd[1]: Starting Apply Kernel Variables...483machine # [ 2.076561] systemd-modules-load[82]: Using 2 probe threads484machine # [ 2.078073] systemd-modules-load[82]: Module 'virtio_balloon' is built in485machine # [ 2.087544] systemd[1]: Started Journal Service.486machine # [ 2.090087] systemd-modules-load[82]: Module 'virtio_console' is built in487machine # [ 2.091523] systemd-modules-load[82]: Inserted module 'dm_mod'488machine # [ 2.092669] systemd-modules-load[82]: Module 'virtio_rng' is built in489machine # [ 2.098205] systemd-modules-load[82]: Inserted module 'virtio_gpu'490machine # [ 2.108563] systemd[1]: Starting Create System Files and Directories...491machine # [ 2.119017] systemd[1]: Finished Apply Kernel Variables.492machine # [ 2.146369] systemd-udevd[89]: Using default interface naming scheme 'v261'.493machine # [ 2.164450] systemd[1]: Finished Create System Files and Directories.494machine # [ 2.183273] systemd[1]: Started Rule-based Manager for Device Events and Files.495machine # [ 2.229409] systemd[1]: Starting Virtual Console Setup...496machine # [ 2.277648] systemd-vconsole-setup[113]: Configuration of first virtual console was skipped, ignoring remaining ones.497machine # [ 2.282959] systemd[1]: Finished Virtual Console Setup.498machine # [ 2.788495] systemd[1]: Finished Coldplug All udev Devices.499machine # [ 2.791604] systemd[1]: Reached target System Initialization.500machine # [ 2.794058] systemd[1]: Reached target Basic System.501machine # [ 3.112505] (udev-worker)[106]: Network interface NamePolicy= disabled on kernel command line.502machine # [ 3.118801] (udev-worker)[110]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.503machine # [ 3.126187] (udev-worker)[110]: Network interface NamePolicy= disabled on kernel command line.504machine # [ 3.186635] systemd[1]: Found device /dev/disk/by-label/nixos.505machine # [ 3.188268] systemd[1]: Reached target Initrd Root Device.506machine # [ 3.192100] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...507machine # [ 3.263766] systemd-fsck[131]: nixos: clean, 12/524288 files, 58513/2097152 blocks508machine # [ 3.277335] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.509machine # [ 3.280563] systemd[1]: Mounting /sysroot...510machine # [ 3.318179] EXT4-fs (vda): mounted filesystem 73be49f4-bbc5-4503-80be-679168e753e9 r/w with ordered data mode. Quota mode: none.511machine # [ 3.320320] systemd[1]: Mounted /sysroot.512machine # [ 3.321912] systemd[1]: Reached target Initrd Root File System.513machine # [ 3.328323] systemd[1]: Starting Mountpoints Configured in the Real Root...514machine # [ 3.353084] systemd-sysroot-fstab-check[139]: /sysroot should be mounted in the initrd, will request daemon-reload.515machine # [ 3.356861] systemd[1]: Reload requested from client PID 139 ('systemd-sysroot') (unit initrd-parse-etc.service)...516machine # [ 3.360072] systemd[1]: Reloading...517machine # [ 3.498544] systemd[1]: Reloading finished in 139 ms.518machine # [ 3.546698] systemd-sysroot-fstab-check[139]: Requesting initrd-fs.target/start/replace...519machine # [ 3.551359] systemd-sysroot-fstab-check[139]: Requesting swap.target/start/replace...520machine # [ 3.554177] systemd[1]: Starting Load Kernel Module 9pnet_virtio...521machine # [ 3.559913] systemd[1]: initrd-parse-etc.service: Deactivated successfully.522machine # [ 3.562663] systemd[1]: Finished Mountpoints Configured in the Real Root.523machine # [ 3.564383] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.524machine # [ 3.590940] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.525machine # [ 3.593284] systemd[1]: Finished Load Kernel Module 9pnet_virtio.526machine # [ 3.843172] systemd[1]: Mounting /sysroot/nix/.ro-store...527machine # [ 3.864320] systemd[1]: Mounting /sysroot/nix/.rw-store...528machine # [ 3.865800] systemd[1]: Mounting /sysroot/run...529machine # [ 3.881813] systemd[1]: Mounting /sysroot/tmp/shared...530machine # [ 3.900897] systemd[1]: Mounting /sysroot/tmp/xchg...531machine # [ 3.903699] systemd[1]: Mounted /sysroot/nix/.ro-store.532machine # [ 3.912714] systemd[1]: Mounted /sysroot/tmp/xchg.533machine # [ 3.925169] systemd[1]: Mounted /sysroot/run.534machine # [ 3.944857] systemd[1]: Mounted /sysroot/nix/.rw-store.535machine # [ 3.974146] systemd[1]: Starting rw-sysroot-nix-store.service...536machine # [ 4.020438] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.537machine # [ 4.032094] systemd[1]: Finished rw-sysroot-nix-store.service.538machine # [ 4.037993] systemd[1]: Mounted /sysroot/tmp/shared.539machine # [ 4.103947] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.540machine # [ 4.107040] (udev-worker)[126]: mtd0ro: Failed to find and pin callout binary "/nix/store/x3ma60wd3w0db1m4dr1xln72q96lnm3b-systemd-261.1/lib/udev/mtd_probe": No such file or directory541machine # [ 4.112706] (udev-worker)[126]: mtd0ro: /nix/store/x3ma60wd3w0db1m4dr1xln72q96lnm3b-systemd-261.1/lib/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 directory542machine # [ 4.118152] systemd[1]: Stopped Virtual Console Setup.543machine # [ 4.119527] systemd[1]: Stopping Virtual Console Setup...544machine # [ 4.120407] systemd[1]: Starting Virtual Console Setup...545machine # [ 4.129105] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.546machine # [ 4.130216] systemd[1]: Stopped Virtual Console Setup.547machine # [ 4.132381] systemd[1]: Starting Virtual Console Setup...548machine # [ 4.153971] systemd-vconsole-setup[174]: Configuration of first virtual console was skipped, ignoring remaining ones.549machine # [ 4.155873] systemd[1]: Finished Virtual Console Setup.550machine # [ 4.836455] systemd[1]: Mounting /sysroot/nix/store...551machine # [ 4.906744] systemd[1]: Mounted /sysroot/nix/store.552machine # [ 4.909319] systemd[1]: Reached target Initrd File Systems.553machine # [ 4.916362] systemd[1]: Starting Find NixOS closure...554machine # [ 4.918808] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...555machine # [ 4.966957] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.556machine # [ 4.973641] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.557machine # [ 4.998191] systemd[1]: Finished Find NixOS closure.558machine # [ 5.000739] systemd[1]: Reached target Initrd Default Target.559machine # [ 5.003261] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...560machine # [ 5.049792] systemd[1]: Stopped target Initrd Default Target.561machine # [ 5.053496] systemd[1]: Stopped target Basic System.562machine # [ 5.055659] systemd[1]: Stopped target Initrd Root Device.563machine # [ 5.058054] systemd[1]: Stopped target Path Units.564machine # [ 5.060140] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.565machine # [ 5.063133] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.566machine # [ 5.066052] systemd[1]: Stopped target Slice Units.567machine # [ 5.067867] systemd[1]: Stopped target Socket Units.568machine # [ 5.072427] systemd[1]: Stopped target System Initialization.569machine # [ 5.076277] systemd[1]: Stopped target Swaps.570machine # [ 5.077781] systemd[1]: Stopped target Timer Units.571machine # [ 5.080245] systemd[1]: dbus.socket: Deactivated successfully.572machine # [ 5.083470] systemd[1]: Closed D-Bus System Message Bus Socket.573machine # [ 5.090239] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.574machine # [ 5.094352] systemd[1]: Stopped Find NixOS closure.575machine # [ 5.095796] systemd[1]: Starting Load Kernel Module 9pnet_virtio...576machine # [ 5.102002] systemd[1]: Starting rw-sysroot-nix-store.service...577machine # [ 5.103402] systemd[1]: systemd-sysctl.service: Deactivated successfully.578machine # [ 5.105039] systemd[1]: Stopped Apply Kernel Variables.579machine # [ 5.108507] systemd[1]: systemd-modules-load.service: Deactivated successfully.580machine # [ 5.111132] systemd[1]: Stopped Load Kernel Modules.581machine # [ 5.112932] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.582machine # [ 5.116826] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.583machine # [ 5.118536] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.584machine # [ 5.120185] systemd[1]: Stopped Create System Files and Directories.585machine # [ 5.122426] systemd[1]: Stopped target Local File Systems.586machine # [ 5.123601] systemd[1]: Stopped target Preparation for Local File Systems.587machine # [ 5.124992] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.588machine # [ 5.126274] systemd[1]: Stopped Coldplug All udev Devices.589machine # [ 5.127264] systemd[1]: Stopping Rule-based Manager for Device Events and Files...590machine # [ 5.128627] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.591machine # [ 5.129921] systemd[1]: Stopped Virtual Console Setup.592machine # [ 5.130867] systemd[1]: initrd-cleanup.service: Deactivated successfully.593machine # [ 5.132146] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.594machine # [ 5.133329] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.595machine # [ 5.134601] systemd[1]: Finished rw-sysroot-nix-store.service.596machine # [ 5.135654] systemd[1]: systemd-udevd.service: Deactivated successfully.597machine # [ 5.136929] systemd[1]: Stopped Rule-based Manager for Device Events and Files.598machine # [ 5.138195] systemd[1]: systemd-udevd.service: Consumed 2.194s CPU time over 3.087s wall clock time, 29.5M memory peak.599machine # [ 5.140017] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.600machine # [ 5.141304] systemd[1]: Finished Load Kernel Module 9pnet_virtio.601machine # [ 5.142401] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.602machine # [ 5.143870] systemd[1]: Closed udev Control Socket.603machine # [ 5.144847] systemd[1]: Starting Cleanup udev Database...604machine # [ 5.145811] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.605machine # [ 5.147134] systemd[1]: Stopped Create Static Device Nodes in /dev.606machine # [ 5.148239] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.607machine # [ 5.149624] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.608machine # [ 5.150856] systemd[1]: kmod-static-nodes.service: Deactivated successfully.609machine # [ 5.152069] systemd[1]: Stopped Create List of Static Device Nodes.610machine # [ 5.194846] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.611machine # [ 5.196595] systemd[1]: Finished Cleanup udev Database.612machine # [ 5.197741] systemd[1]: Reached target Switch Root.613machine # [ 5.198835] systemd[1]: Starting NixOS Activation...614machine # [ 5.427790] initrd-nixos-activation-start[201]: booting system configuration /nix/store/iwslnprwa8kiyh0cr3n6xw3nrp6w6ck7-nixos-system-machine-test615machine # [ 5.501201] initrd-nixos-activation-start[201]: running activation script...616machine # [ 5.997497] initrd-nixos-activation-start[224]: setting up /etc...617machine # [ 6.283879] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.618machine # [ 6.285334] systemd[1]: Finished NixOS Activation.619machine # [ 6.288321] systemd[1]: Starting Switch Root...620machine # [ 6.318656] systemd[1]: Switching root.621machine # [ 6.447610] systemd-journald[81]: Received SIGTERM from PID 1 (systemd).622machine # [ 7.139947] systemd[1]: systemd 261.1 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)623machine # [ 7.143333] systemd[1]: Detected virtualization qemu.624machine # [ 7.143476] systemd[1]: Detected architecture arm64.625machine # [ 7.143716] systemd[1]: Detected first boot.626machine # [ 7.165368] systemd[1]: Initializing machine ID from random generator.627machine # [ 7.451401] systemd[1]: bpf-restrict-fs: LSM BPF program attached628machine # [ 7.632386] systemd[1]: Applying preset policy.629machine # [ 8.184684] systemd[1]: Populated /etc with preset unit settings.630machine # [ 8.733651] systemd[1]: initrd-switch-root.service: Deactivated successfully.631machine # [ 8.734852] systemd[1]: Stopped initrd-switch-root.service.632machine # [ 8.740714] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.633machine # [ 8.746958] systemd[1]: Created slice Slice /system/getty.634machine # [ 8.750505] systemd[1]: Created slice User and Session Slice.635machine # [ 8.752304] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.636machine # [ 8.753731] systemd[1]: Started Forward Password Requests to Wall Directory Watch.637machine # [ 8.754941] systemd[1]: Expecting device /dev/hvc0...638machine # [ 8.757956] systemd[1]: Expecting device /dev/ttyAMA0...639machine # [ 8.759111] systemd[1]: Reached target Local Encrypted Volumes.640machine # [ 8.760350] systemd[1]: Stopped target initrd-fs.target.641machine # [ 8.761463] systemd[1]: Stopped target initrd-root-fs.target.642machine # [ 8.762580] systemd[1]: Stopped target initrd-switch-root.target.643machine # [ 8.763746] systemd[1]: Reached target Virtual Machines and Containers.644machine # [ 8.764901] systemd[1]: Reached target Path Units.645machine # [ 8.766052] systemd[1]: Reached target Remote File Systems.646machine # [ 8.767060] systemd[1]: Reached target Slice Units.647machine # [ 8.768113] systemd[1]: Reached target Swaps.648machine # [ 8.779569] systemd[1]: Listening on Query the User Interactively for a Password.649machine # [ 8.787469] systemd[1]: Listening on Process Core Dump Socket.650machine # [ 8.793404] systemd[1]: Listening on Credential Encryption/Decryption.651machine # [ 8.799892] systemd[1]: Listening on Factory Reset Management.652machine # [ 8.801383] systemd[1]: Listening on Hostname Service Socket.653machine # [ 8.812112] systemd[1]: Starting Journal Log Access Socket...654machine # [ 8.814436] systemd[1]: Listening on Journal Audit Socket.655machine # [ 8.821130] systemd[1]: Listening on Console Output Muting Service Socket.656machine # [ 8.822933] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.657machine # [ 8.824181] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os658machine # [ 8.825193] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki659machine # [ 8.843973] systemd[1]: Listening on Disk Repartitioning Service Socket.660machine # [ 8.845297] systemd[1]: Listening on udev Control Socket.661machine # [ 8.846577] systemd[1]: Listening on udev Varlink Socket.662machine # [ 8.853119] systemd[1]: Mounting Huge Pages File System...663machine # [ 8.859469] systemd[1]: Mounting POSIX Message Queue File System...664machine # [ 8.867270] systemd[1]: Mounting Kernel Debug File System...665machine # [ 8.879430] systemd[1]: Mounting Kernel Trace File System...666machine # [ 8.889700] systemd[1]: Starting Create List of Static Device Nodes...667machine # [ 8.901360] systemd[1]: Starting Load Kernel Module 9pnet_virtio...668machine # [ 8.903415] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs669machine # [ 8.909898] systemd[1]: Mounting Kernel Configuration File System...670machine # [ 8.910967] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm671machine # [ 8.911751] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore672machine # [ 8.922632] systemd[1]: Starting Load Kernel Module fuse...673machine # [ 8.924479] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67674machine # [ 8.939785] systemd[1]: Starting Journal Service...675machine # [ 8.988153] systemd[1]: Starting Load Kernel Modules...676machine # [ 9.014434] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...677machine # [ 9.023447] systemd[1]: Starting Remount Root and Kernel File Systems...678machine # [ 9.024015] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os679machine # [ 9.039645] systemd[1]: Starting Coldplug All udev Devices...680machine # [ 9.044840] systemd[1]: Listening on Journal Log Access Socket.681machine # [ 9.045996] systemd[1]: Mounted Huge Pages File System.682machine # [ 9.047684] systemd[1]: Mounted POSIX Message Queue File System.683machine # [ 9.048451] systemd[1]: Mounted Kernel Debug File System.684machine # [ 9.049282] systemd[1]: Mounted Kernel Trace File System.685machine # [ 9.050481] systemd[1]: Mounted Kernel Configuration File System.686machine # [ 9.095365] systemd[1]: Finished Create List of Static Device Nodes.687machine # [ 9.099542] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...688machine # [ 9.120166] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.689machine # [ 9.127969] systemd-journald[295]: Collecting audit messages is enabled.690machine # [ 9.136001] systemd[1]: Finished Load Kernel Module 9pnet_virtio.691machine # [ 9.143394] systemd[1]: Started Journal Service.692machine # [ 9.141494] systemd[1]: Queued start job for default target Multi-User System.693machine # [ 9.150254] systemd[1]: systemd-journald.service: Deactivated successfully.694machine # [ 9.162918] fuse: init (API version 7.45)695machine # [ 9.162080] systemd-modules-load[297]: Using 2 probe threads696machine # [ 9.166160] systemd-modules-load[297]: Module 'atkbd' is built in697machine # [ 9.174067] systemd-modules-load[297]: Module 'loop' is built in698machine # [ 9.176522] systemd[1]: Finished Load Kernel Modules.699machine # [ 9.179370] systemd[1]: Starting Apply Kernel Variables...700machine # [ 9.184007] EXT4-fs (vda): re-mounted 73be49f4-bbc5-4503-80be-679168e753e9.701machine # [ 9.188428] systemd[1]: modprobe@fuse.service: Deactivated successfully.702machine # [ 9.201133] systemd[1]: Finished Load Kernel Module fuse.703machine # [ 9.203520] systemd[1]: Finished Remount Root and Kernel File Systems.704machine # [ 9.209150] systemd[1]: Listening on Disk Image Download Service Socket.705machine # [ 9.214104] systemd-oomd[298]: No swap; memory pressure usage will be degraded706machine # [ 9.218327] systemd[1]: Mounting FUSE Control File System...707machine # [ 9.236650] systemd[1]: Starting Flush Journal to Persistent Storage...708machine # [ 9.240127] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore709machine # [ 9.251778] systemd[1]: Starting Load/Save OS Random Seed...710machine # [ 9.256145] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os711machine # [ 9.258063] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.712machine # [ 9.259230] systemd[1]: Mounted FUSE Control File System.713machine # [ 9.298463] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.714machine # [ 9.305261] systemd[1]: Starting Create Static Device Nodes in /dev...715machine # [ 9.306576] systemd[1]: Finished Apply Kernel Variables.716machine # [ 9.323491] systemd-journald[295]: Received client request to flush runtime journal.717machine # [ 9.349861] systemd[1]: Finished Load/Save OS Random Seed.718machine # [ 9.351642] systemd[1]: Reached target First Boot Complete.719machine # [ 9.355011] systemd[1]: Finished Flush Journal to Persistent Storage.720machine # [ 9.395210] systemd[1]: Finished Create Static Device Nodes in /dev.721machine # [ 9.396644] systemd[1]: Reached target Preparation for Local File Systems.722machine # [ 9.399025] systemd[1]: Starting Rule-based Manager for Device Events and Files...723machine # [ 9.481738] systemd-udevd[328]: Using default interface naming scheme 'v261'.724machine # [ 9.583990] systemd[1]: Started Rule-based Manager for Device Events and Files.725machine # [ 9.740135] systemd[1]: Mounting /run/wrappers...726machine # [ 9.805983] systemd[1]: Mounted /run/wrappers.727machine # [ 9.815090] systemd[1]: Reached target Local File Systems.728machine # [ 9.816151] systemd[1]: Listening on Boot Loader Control Service Socket.729machine # [ 9.820168] systemd[1]: Starting register-nix-paths.service...730machine # [ 9.827329] systemd[1]: Starting Create SUID/SGID Wrappers...731machine # [ 9.840369] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.732machine # [ 9.843633] systemd[1]: Starting Save Transient machine-id to Disk...733machine # [ 9.852363] systemd[1]: Starting Create System Files and Directories...734machine # [ 9.876243] systemd[1]: Finished Coldplug All udev Devices.735machine # [ 9.917168] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.736machine # [ 9.921240] systemd[1]: Finished Save Transient machine-id to Disk.737machine # [ 9.942019] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs738machine # [ 10.001491] systemd[1]: Finished Create System Files and Directories.739machine # [ 10.014814] systemd[1]: Starting Rebuild Journal Catalog...740machine # [ 10.017808] systemd[1]: Starting Record System Boot/Shutdown in UTMP...741machine # [ 10.092962] systemd[1]: Finished Record System Boot/Shutdown in UTMP.742machine # [ 10.096077] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.743machine # [ 10.127415] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.744machine # [ 10.151438] systemd[1]: Finished Rebuild Journal Catalog.745machine # [ 10.157420] systemd[1]: Starting Update is Completed...746machine # [ 10.226113] systemd[1]: Finished Update is Completed.747machine # [ 10.362774] (udev-worker)[351]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.748machine # [ 10.372723] (udev-worker)[351]: Network interface NamePolicy= disabled on kernel command line.749machine # [ 10.382611] (udev-worker)[360]: Network interface NamePolicy= disabled on kernel command line.750machine # [ 10.452248] systemd[1]: Condition check resulted in Virtio network device being skipped.751machine # [ 10.454540] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore752machine # [ 10.456727] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.753machine # [ 10.458336] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67754machine # [ 10.461296] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore755machine # [ 10.463338] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os756machine # [ 10.467809] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os757machine # [ 10.537307] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.758machine # [ 10.540352] systemd[1]: Finished Create SUID/SGID Wrappers.759machine # [ 10.558899] mousedev: PS/2 mouse device common for all mice760machine # [ 10.739723] systemd[1]: Finished register-nix-paths.service.761machine # [ 10.742903] systemd[1]: Reached target System Initialization.762machine # [ 10.760295] systemd[1]: Started Discard unused filesystem blocks once a week.763machine # [ 10.762331] systemd[1]: Started Daily Cleanup of Temporary Directories.764machine # [ 10.764146] systemd[1]: Reached target Timer Units.765machine # [ 10.765331] systemd[1]: Listening on D-Bus System Message Bus Socket.766machine # [ 10.766790] systemd[1]: Listening on Nix Daemon Socket.767machine # [ 10.769653] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.768machine # [ 10.771584] systemd[1]: Reached target Socket Units.769machine # [ 10.774350] systemd[1]: Reached target Basic System.770machine # [ 10.776310] systemd[1]: Started backdoor.service.771machine # [ 10.777468] systemd[1]: Starting Import lastlog data into lastlog2 database...772machine # [ 10.780479] systemd[1]: Starting Name Service Cache Daemon (nsncd)...773machine # [ 10.781911] systemd[1]: Starting Post-Boot Actions...774machine # [ 10.783635] systemd[1]: Started Reset console on configuration changes.775machine # [ 10.785972] systemd[1]: Starting resolvconf update...776machine # [ 10.794437] systemd[1]: Started rustfs.service.777machine # [ 10.804653] systemd[1]: Starting rustfs-setup.service...778machine # [ 10.812176] systemd[1]: Starting D-Bus System Message Bus...779machine # connecting to host...780machine # [ 10.978284] systemd[1]: Started Name Service Cache Daemon (nsncd).781machine # [ 10.988701] nsncd[433]: Aug 27 17:07:34.736 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"782machine # [ 10.998459] systemd[1]: Reached target Host and Network Name Lookups.783machine # [ 10.999913] systemd[1]: Reached target User and Group Name Lookups.784machine: Guest shell says: b'Spawning backdoor root shell...\n'785machine # [ 11.011285] systemd[1]: Starting User Login Management...786machine # [ 11.017719] systemd[1]: Finished Post-Boot Actions.787machine: connected to guest root shell788machine: (connecting took 11.37 seconds)789machine: (finished: waiting for the VM to finish booting, in 11.85 seconds)790machine # [ 11.039865] systemd[1]: Finished Import lastlog data into lastlog2 database.791machine # [ 11.088891] dbus-broker-launch[439]: Looking up NSS user entry for 'systemd-timesync'...792machine # [ 11.116316] dbus-broker-launch[439]: NSS returned no entry for 'systemd-timesync'793machine # [ 11.121995] dbus-broker-launch[439]: Invalid user-name in /nix/store/bh3fp7cxg1w52wyn4ni6zbspa5nqv5yq-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"794machine # [ 11.174633] systemd[1]: Started D-Bus System Message Bus.795machine # [ 11.182781] systemd-logind[463]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)796machine # [ 11.189849] systemd-logind[463]: Watching system buttons on /dev/input/event0 (gpio-keys)797machine # [ 11.201208] systemd-logind[463]: New seat seat0.798machine # [ 11.205874] systemd[1]: Started User Login Management.799machine # [ 11.211779] dbus-broker-launch[439]: Ready800machine # [ 11.216638] systemd[1]: Starting linger-users.service...801machine # [ 11.265171] systemd[1]: Stopped target Host and Network Name Lookups.802machine # [ 11.269965] systemd[1]: Stopping Host and Network Name Lookups...803machine # [ 11.278387] systemd[1]: Stopped target User and Group Name Lookups.804machine # [ 11.280612] systemd[1]: Stopping User and Group Name Lookups...805machine # [ 11.281910] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...806machine # [ 11.284063] systemd[1]: nscd.service: Deactivated successfully.807machine # [ 11.286136] systemd[1]: Stopped Name Service Cache Daemon (nsncd).808machine # [ 11.289422] systemd[1]: Starting Name Service Cache Daemon (nsncd)...809machine # [ 11.307859] systemd[1]: linger-users.service: Deactivated successfully.810machine # [ 11.320869] systemd[1]: Finished linger-users.service.811machine # [ 11.364894] systemd[1]: Started Name Service Cache Daemon (nsncd).812machine # [ 11.369769] systemd[1]: Reached target Host and Network Name Lookups.813machine # [ 11.374398] nsncd[525]: Aug 27 17:07:35.121 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"814machine # [ 11.377199] systemd[1]: Reached target User and Group Name Lookups.815machine # [ 11.422942] systemd[1]: Finished resolvconf update.816machine # [ 11.426479] systemd[1]: Reached target Preparation for Network.817machine # [ 11.437074] systemd[1]: Starting DHCP Client...818machine # [ 11.447446] systemd[1]: Starting Address configuration of eth1...819machine # [ 11.452545] systemd[1]: Starting Extra networking commands....820machine # [ 11.626652] network-addresses-eth1-start[559]: adding address 192.168.1.1/24... done821machine # [ 11.651398] network-addresses-eth1-start[559]: adding address 2001:db8:1::1/64... done822machine # [ 11.678276] systemd[1]: Finished Address configuration of eth1.823machine # [ 11.698936] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:09.0/virtio8/input/input3824machine # [ 11.727803] dhcpcd[567]: dhcpcd-10.3.2 starting825machine # [ 11.748133] dhcpcd[601]: dev: loaded udev826machine # [ 11.795763] 8021q: 802.1Q VLAN Support v1.8827machine # [ 11.796204] 8021q: adding VLAN 0 to HW filter on device eth1828machine # [ 11.872567] systemd[1]: Finished Extra networking commands..829machine # [ 11.873874] systemd[1]: Reached target Network.[ 11.876741] cfg80211: Loading compiled-in X.509 certificates for regulatory database830machine # 831machine # [ 11.883415] systemd[1]: Starting PostgreSQL Server...832machine # [ 11.891426] systemd[1]: Starting Permit User Sessions...833machine # [ 11.924797] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'834machine # [ 11.925369] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'835machine # [ 11.934977] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2836machine # [ 11.935509] cfg80211: failed to load regulatory.db837machine # [ 11.984829] systemd[1]: Finished Permit User Sessions.838machine # [ 11.989081] systemd[1]: Started Getty on tty1.839machine # [ 11.991321] systemd[1]: Reached target Login Prompts.840machine # [ 12.089327] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.841machine # [ 12.106675] 8021q: adding VLAN 0 to HW filter on device eth0842machine # [ 12.107090] dhcpcd[601]: eth0: waiting for carrier843machine # [ 12.109943] dhcpcd[601]: libudev: received NULL device844machine # [ 12.111066] dhcpcd[601]: libudev: received NULL device845machine # [ 12.112170] dhcpcd[601]: eth0: carrier acquired846machine # [ 12.129152] systemd[1]: Starting Virtual Console Setup...847machine # [ 12.140134] dhcpcd[601]: DUID 00:01:00:01:32:23:2b:57:52:54:00:12:34:56848machine # [ 12.141386] dhcpcd[601]: eth0: IAID 00:12:34:56849machine # [ 12.142121] dhcpcd[601]: eth0: adding address fe80::5054:ff:fe12:3456850machine # [ 12.151422] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.851machine # [ 12.155198] systemd[1]: Stopped Virtual Console Setup.852machine # [ 12.163665] systemd-logind[463]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)853machine # [ 12.166131] systemd[1]: Starting Virtual Console Setup...854machine # [ 12.332450] postgresql-pre-start[658]: The files belonging to this database system will be owned by user "postgres".855machine # [ 12.338189] postgresql-pre-start[658]: This user must also own the server process.856machine # [ 12.343825] postgresql-pre-start[658]: The database cluster will be initialized with locale "en_US.UTF-8".857machine # [ 12.345819] postgresql-pre-start[658]: The default database encoding has accordingly been set to "UTF8".858machine # [ 12.347231] postgresql-pre-start[658]: The default text search configuration will be set to "english".859machine # [ 12.349538] postgresql-pre-start[658]: Data page checksums are enabled.860machine # [ 12.352058] postgresql-pre-start[658]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok861machine # [ 12.354599] postgresql-pre-start[658]: creating subdirectories ... ok862machine # [ 12.357715] postgresql-pre-start[658]: selecting dynamic shared memory implementation ... posix863machine # [ 12.458339] postgresql-pre-start[658]: selecting default "max_connections" ... 100864machine # [ 12.541290] postgresql-pre-start[658]: selecting default "shared_buffers" ... 128MB865machine # [ 12.632735] systemd-vconsole-setup[659]: Configuration of first virtual console was skipped, ignoring remaining ones.866machine # [ 12.638263] systemd[1]: Finished Virtual Console Setup.867machine # [ 12.719818] dhcpcd[601]: eth0: soliciting a DHCP lease868machine # [ 12.728627] dhcpcd[601]: eth0: offered 10.0.2.15 from 10.0.2.2869machine # [ 12.736366] dhcpcd[601]: eth0: probing address 10.0.2.15/24870machine # [ 14.118206] dhcpcd[601]: eth0: soliciting an IPv6 router871machine # [ 14.118527] dhcpcd[601]: eth0: Router Advertisement from fe80::2872machine # [ 14.118765] dhcpcd[601]: eth0: adding address fec0::5054:ff:fe12:3456/64873machine # [ 14.118941] dhcpcd[601]: eth0: adding route to fec0::/64874machine # [ 14.119101] dhcpcd[601]: eth0: adding default route via fe80::2875machine # [ 14.697228] postgresql-pre-start[658]: selecting default time zone ... UTC876machine # [ 14.702558] postgresql-pre-start[658]: creating configuration files ... ok877machine # [ 14.973471] postgresql-pre-start[658]: running bootstrap script ... ok878machine # [ 15.732541] postgresql-pre-start[658]: performing post-bootstrap initialization ... ok879machine # [ 15.919321] postgresql-pre-start[658]: syncing data to disk ... ok880machine # [ 15.921242] postgresql-pre-start[658]: initdb: warning: enabling "trust" authentication for local connections881machine # [ 15.924865] postgresql-pre-start[658]: 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.882machine # [ 15.929363] postgresql-pre-start[658]: Success. You can now start the database server using:883machine # [ 15.931989] postgresql-pre-start[658]: pg_ctl -D /var/lib/postgresql/18 -l logfile start884machine # [ 16.143942] postgres[713]: [713] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit885machine # [ 16.149080] postgres[713]: [713] LOG: listening on IPv4 address "0.0.0.0", port 5432886machine # [ 16.152709] postgres[713]: [713] LOG: listening on IPv6 address "::", port 5432887machine # [ 16.155665] postgres[713]: [713] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"888machine # [ 16.172067] postgres[727]: [727] LOG: database system was shut down at 2026-08-27 17:07:39 GMT889machine # [ 16.181152] postgres[713]: [713] LOG: database system is ready to accept connections890machine # [ 16.189528] systemd[1]: Started PostgreSQL Server.891machine # [ 16.197950] systemd[1]: Starting PostgreSQL Setup Scripts...892machine # [ 16.588507] postgresql-setup-start[738]: CREATE DATABASE893machine # [ 16.648468] postgresql-setup-start[743]: CREATE ROLE894machine # [ 16.681133] postgresql-setup-start[745]: ALTER DATABASE895machine # [ 16.688738] systemd[1]: Finished PostgreSQL Setup Scripts.896machine # [ 16.690618] systemd[1]: Reached target PostgreSQL.897machine # [ 17.555324] dhcpcd[601]: eth0: leased 10.0.2.15 for 86400 seconds898machine # [ 17.555727] dhcpcd[601]: eth0: adding route to 10.0.2.0/24899machine # [ 17.555884] dhcpcd[601]: eth0: adding default route via 10.0.2.2900machine # [ 17.811568] systemd[1]: Started DHCP Client.901machine # [ 17.823509] systemd[1]: Reached target Network is Online.902machine # [ 17.831006] systemd[1]: Starting k3s service...903machine # [ 17.998267] k3s[815]: time="2026-08-27T17:07:41Z" level=info msg="Acquiring lock file /var/lib/rancher/k3s/data/.lock"904machine # [ 18.002991] k3s[815]: time="2026-08-27T17:07:41Z" level=info msg="Preparing data dir /var/lib/rancher/k3s/data/2e5bda2274993078a017825bb1de943c594b70f5ddab0db92d8d7e4298306bc0"905machine # [ 22.901409] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Starting k3s 1.35.7+k3s1 (cd43afc7)"906machine # [ 22.908494] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdle=20, maxOpen=0, maxLifetime=0s, maxIdleTime=2m0s"907machine # [ 22.912274] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Kine built with sqlite from github.com/mattn/go-sqlite3 version 3.53.3"908machine # [ 22.915127] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Configuring database table schema and indexes, this may take a moment..."909machine # [ 22.920720] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Database tables and indexes are up to date"910machine # [ 22.923051] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Running startup VACUUM to reclaim disk space, this may take a moment..."911machine # [ 22.925992] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Startup VACUUM completed successfully"912machine # [ 22.931983] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Kine available at unix://kine.sock"913machine # [ 22.934116] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"914machine # [ 22.939421] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="Datastore connection validated successfully, proceeding with bootstrap data generation"915machine # [ 22.948355] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="generated self-signed CA certificate CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:46.7005763 +0000 UTC notAfter=2036-08-24 16:07:46.7005763 +0000 UTC"916machine # [ 22.952262] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"917machine # [ 22.955973] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"918machine # [ 22.959959] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"919machine # [ 22.963733] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"920machine # [ 22.967238] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"921machine # [ 22.970746] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"922machine # [ 22.974011] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="generated self-signed CA certificate CN=k3s-server-ca@1787850466: notBefore=2026-08-27 16:07:46.7166247 +0000 UTC notAfter=2036-08-24 16:07:46.7166247 +0000 UTC"923machine # [ 22.977116] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-server-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"924machine # [ 22.979909] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=kube-scheduler signed by CN=k3s-server-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"925machine # [ 22.982861] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=kube-controller-manager signed by CN=k3s-server-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"926machine # [ 22.985758] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="generated self-signed CA certificate CN=k3s-request-header-ca@1787850466: notBefore=2026-08-27 16:07:46.72252854 +0000 UTC notAfter=2036-08-24 16:07:46.72252854 +0000 UTC"927machine # [ 22.988733] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"928machine # [ 22.991435] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="generated self-signed CA certificate CN=etcd-server-ca@1787850466: notBefore=2026-08-27 16:07:46.72484672 +0000 UTC notAfter=2036-08-24 16:07:46.72484672 +0000 UTC"929machine # [ 22.994316] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"930machine # [ 22.996835] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="generated self-signed CA certificate CN=etcd-peer-ca@1787850466: notBefore=2026-08-27 16:07:46.72725238 +0000 UTC notAfter=2036-08-24 16:07:46.72725238 +0000 UTC"931machine # [ 22.999409] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"932machine # [ 23.001883] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"933machine # [ 23.004298] k3s[815]: time="2026-08-27T17:07:46Z" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1787850466: notBefore=2026-08-27 16:07:46 +0000 UTC notAfter=2027-08-27 16:07:46 +0000 UTC"934machine # [ 23.012117] k3s[815]: time="2026-08-27T17:07:46Z" level=warning msg="dynamiclistener [::]:6443: no cached certificate available for preload - deferring certificate load until storage initialization or first client request"935machine # [ 23.014792] k3s[815]: time="2026-08-27T17:07:46Z" 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__55d6_1ccb_f2c5_cfd8-a95230:fec0::55d6:1ccb:f2c5:cfd8 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=7B63E4D2B883A0A342925D6935FE6FFA00D2FAF7]"936machine # [ 23.489139] rustfs-setup-start[851]: mb s3://niks3937machine # [ 23.497995] systemd[1]: Finished rustfs-setup.service.938machine # [ 24.407061] k3s[815]: time="2026-08-27T17:07:48Z" level=info msg="Password verified locally for node machine"939machine # [ 24.409453] k3s[815]: time="2026-08-27T17:07:48Z" level=info msg="certificate CN=machine signed by CN=k3s-server-ca@1787850466: notBefore=2026-08-27 16:07:48 +0000 UTC notAfter=2027-08-27 16:07:48 +0000 UTC"940machine # [ 25.089556] k3s[815]: time="2026-08-27T17:07:48Z" level=info msg="certificate CN=system:node:machine,O=system:nodes signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:48 +0000 UTC notAfter=2027-08-27 16:07:48 +0000 UTC"941machine # [ 25.321970] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:49 +0000 UTC notAfter=2027-08-27 16:07:49 +0000 UTC"942machine # [ 25.459937] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1787850466: notBefore=2026-08-27 16:07:49 +0000 UTC notAfter=2027-08-27 16:07:49 +0000 UTC"943machine # [ 25.561848] k3s[815]: time="2026-08-27T17:07:49Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:52222: runtime core not ready"944machine # [ 25.684136] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Module overlay was already loaded"945machine # [ 25.778686] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.946machine # [ 25.785986] Bridge firewalling registered947machine # [ 25.805058] k3s[815]: time="2026-08-27T17:07:49Z" level=warning msg="Failed to load kernel module iptable_nat with modprobe"948machine # [ 25.820424] k3s[815]: time="2026-08-27T17:07:49Z" level=warning msg="Failed to load kernel module iptable_filter with modprobe"949machine # [ 25.833935] k3s[815]: time="2026-08-27T17:07:49Z" level=warning msg="Failed to load kernel module nft-expr-counter with modprobe"950machine # [ 25.913838] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Set sysctl 'net/ipv4/conf/all/forwarding' to 1"951machine # [ 25.915761] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 131072"952machine # [ 25.917647] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400"953machine # [ 25.919668] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600"954machine # [ 25.926922] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Creating k3s-cert-monitor event broadcaster"955machine # [ 25.931988] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Polling for API server readiness: GET /readyz failed: the server is currently unable to handle the request"956machine # [ 25.934152] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"957machine # [ 25.935691] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Saving cluster bootstrap data to datastore"958machine # [ 25.937370] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"959machine # [ 25.939189] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Connection to etcd is ready"960machine # [ 25.940553] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="ETCD server is now running"961machine # [ 25.943397] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Handling backend connection request [machine]"962machine # [ 25.948166] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"963machine # [ 25.949789] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"964machine # [ 25.951502] k3s[815]: time="2026-08-27T17:07:49Z" 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"965machine # [ 25.988214] k3s[815]: time="2026-08-27T17:07:49Z" 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"966machine # [ 26.009233] k3s[815]: time="2026-08-27T17:07:49Z" 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"967machine # [ 26.059827] k3s[815]: time="2026-08-27T17:07:49Z" 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"968machine # [ 26.073721] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Server node token is available at /var/lib/rancher/k3s/server/token"969machine # [ 26.077785] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="To join server node to cluster: k3s server -s https://10.0.2.15:6443 -t ${SERVER_NODE_TOKEN}"970machine # [ 26.080672] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Agent node token is available at /var/lib/rancher/k3s/server/agent-token"971machine # [ 26.083175] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="To join agent node to cluster: k3s agent -s https://10.0.2.15:6443 -t ${AGENT_NODE_TOKEN}"972machine # [ 26.092200] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"973machine # [ 26.094164] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Run: k3s kubectl"974machine # [ 26.095606] k3s[815]: I0827 17:07:49.737819 815 options.go:263] external host was not specified, using 10.0.2.15975machine # [ 26.100123] k3s[815]: I0827 17:07:49.740419 815 server.go:158] Version: v1.35.7+k3s1976machine # [ 26.101558] k3s[815]: I0827 17:07:49.740473 815 server.go:160] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""977machine # [ 26.103391] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log"978machine # [ 26.105652] k3s[815]: time="2026-08-27T17:07:49Z" level=info msg="Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml"979machine # [ 26.144070] k3s[815]: time="2026-08-27T17:07:49Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:52274: runtime core not ready"980machine # [ 26.218992] k3s[815]: I0827 17:07:49.976324 815 shared_informer.go:349] "Waiting for caches to sync" controller="node_authorizer"981machine # [ 26.224508] k3s[815]: I0827 17:07:49.981870 815 plugins.go:157] Loaded 14 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,PodTopologyLabels,MutatingAdmissionPolicy,MutatingAdmissionWebhook.982machine # [ 26.232272] k3s[815]: I0827 17:07:49.986998 815 plugins.go:160] Loaded 14 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,ClusterTrustBundleAttest,CertificateSubjectRestriction,NodeDeclaredFeatureValidator,ValidatingAdmissionPolicy,ValidatingAdmissionWebhook,ResourceQuota.983machine # [ 26.237310] k3s[815]: I0827 17:07:49.987597 815 instance.go:240] Using reconciler: lease984machine # [ 26.238475] k3s[815]: I0827 17:07:49.988311 815 shared_informer.go:370] "Waiting for caches to sync"985machine # [ 26.248112] k3s[815]: I0827 17:07:50.004176 815 handler.go:304] Adding GroupVersion apiextensions.k8s.io v1 to ResourceManager986machine # [ 26.249943] k3s[815]: W0827 17:07:50.004235 815 genericapiserver.go:787] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.987machine # [ 26.256149] k3s[815]: I0827 17:07:50.012458 815 cidrallocator.go:198] starting ServiceCIDR Allocator Controller988machine # [ 26.322610] k3s[815]: I0827 17:07:50.079779 815 handler.go:304] Adding GroupVersion v1 to ResourceManager989machine # [ 26.324161] k3s[815]: I0827 17:07:50.080081 815 apis.go:112] API group "internal.apiserver.k8s.io" is not enabled, skipping.990machine # [ 26.376613] k3s[815]: time="2026-08-27T17:07:50Z" 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"991machine # [ 26.395796] k3s[815]: I0827 17:07:50.153154 815 apis.go:112] API group "storagemigration.k8s.io" is not enabled, skipping.992machine # [ 26.491271] k3s[815]: I0827 17:07:50.248080 815 handler.go:304] Adding GroupVersion authentication.k8s.io v1 to ResourceManager993machine # [ 26.494685] k3s[815]: W0827 17:07:50.248184 815 genericapiserver.go:787] Skipping API authentication.k8s.io/v1beta1 because it has no resources.994machine # [ 26.496932] k3s[815]: W0827 17:07:50.248198 815 genericapiserver.go:787] Skipping API authentication.k8s.io/v1alpha1 because it has no resources.995machine # [ 26.499239] k3s[815]: I0827 17:07:50.249379 815 handler.go:304] Adding GroupVersion authorization.k8s.io v1 to ResourceManager996machine # [ 26.501268] k3s[815]: W0827 17:07:50.249402 815 genericapiserver.go:787] Skipping API authorization.k8s.io/v1beta1 because it has no resources.997machine # [ 26.503480] k3s[815]: I0827 17:07:50.252303 815 handler.go:304] Adding GroupVersion autoscaling v2 to ResourceManager998machine # [ 26.505396] k3s[815]: I0827 17:07:50.253283 815 handler.go:304] Adding GroupVersion autoscaling v1 to ResourceManager999machine # [ 26.507173] k3s[815]: W0827 17:07:50.253304 815 genericapiserver.go:787] Skipping API autoscaling/v2beta1 because it has no resources.1000machine # [ 26.509008] k3s[815]: W0827 17:07:50.253314 815 genericapiserver.go:787] Skipping API autoscaling/v2beta2 because it has no resources.1001machine # [ 26.510761] k3s[815]: I0827 17:07:50.255001 815 handler.go:304] Adding GroupVersion batch v1 to ResourceManager1002machine # [ 26.512197] k3s[815]: W0827 17:07:50.255032 815 genericapiserver.go:787] Skipping API batch/v1beta1 because it has no resources.1003machine # [ 26.514016] k3s[815]: I0827 17:07:50.255942 815 handler.go:304] Adding GroupVersion certificates.k8s.io v1 to ResourceManager1004machine # [ 26.515719] k3s[815]: W0827 17:07:50.255965 815 genericapiserver.go:787] Skipping API certificates.k8s.io/v1beta1 because it has no resources.1005machine # [ 26.517805] k3s[815]: W0827 17:07:50.255974 815 genericapiserver.go:787] Skipping API certificates.k8s.io/v1alpha1 because it has no resources.1006machine # [ 26.519678] k3s[815]: I0827 17:07:50.256595 815 handler.go:304] Adding GroupVersion coordination.k8s.io v1 to ResourceManager1007machine # [ 26.521522] k3s[815]: W0827 17:07:50.256616 815 genericapiserver.go:787] Skipping API coordination.k8s.io/v1beta1 because it has no resources.1008machine # [ 26.524775] k3s[815]: W0827 17:07:50.256624 815 genericapiserver.go:787] Skipping API coordination.k8s.io/v1alpha2 because it has no resources.1009machine # [ 26.526783] k3s[815]: I0827 17:07:50.257209 815 handler.go:304] Adding GroupVersion discovery.k8s.io v1 to ResourceManager1010machine # [ 26.528535] k3s[815]: W0827 17:07:50.257224 815 genericapiserver.go:787] Skipping API discovery.k8s.io/v1beta1 because it has no resources.1011machine # [ 26.530552] k3s[815]: I0827 17:07:50.259823 815 handler.go:304] Adding GroupVersion networking.k8s.io v1 to ResourceManager1012machine # [ 26.532298] k3s[815]: W0827 17:07:50.259856 815 genericapiserver.go:787] Skipping API networking.k8s.io/v1beta1 because it has no resources.1013machine # [ 26.534021] k3s[815]: I0827 17:07:50.260387 815 handler.go:304] Adding GroupVersion node.k8s.io v1 to ResourceManager1014machine # [ 26.535718] k3s[815]: W0827 17:07:50.260406 815 genericapiserver.go:787] Skipping API node.k8s.io/v1beta1 because it has no resources.1015machine # [ 26.537608] k3s[815]: W0827 17:07:50.260412 815 genericapiserver.go:787] Skipping API node.k8s.io/v1alpha1 because it has no resources.1016machine # [ 26.539439] k3s[815]: I0827 17:07:50.261178 815 handler.go:304] Adding GroupVersion policy v1 to ResourceManager1017machine # [ 26.541210] k3s[815]: W0827 17:07:50.261237 815 genericapiserver.go:787] Skipping API policy/v1beta1 because it has no resources.1018machine # [ 26.543004] k3s[815]: I0827 17:07:50.263166 815 handler.go:304] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager1019machine # [ 26.544876] k3s[815]: W0827 17:07:50.263202 815 genericapiserver.go:787] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.1020machine # [ 26.547006] k3s[815]: W0827 17:07:50.263214 815 genericapiserver.go:787] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.1021machine # [ 26.549126] k3s[815]: I0827 17:07:50.263727 815 handler.go:304] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager1022machine # [ 26.550880] k3s[815]: W0827 17:07:50.263746 815 genericapiserver.go:787] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.1023machine # [ 26.552876] k3s[815]: W0827 17:07:50.263756 815 genericapiserver.go:787] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.1024machine # [ 26.554809] k3s[815]: I0827 17:07:50.266412 815 handler.go:304] Adding GroupVersion storage.k8s.io v1 to ResourceManager1025machine # [ 26.556556] k3s[815]: W0827 17:07:50.266455 815 genericapiserver.go:787] Skipping API storage.k8s.io/v1beta1 because it has no resources.1026machine # [ 26.558564] k3s[815]: W0827 17:07:50.266464 815 genericapiserver.go:787] Skipping API storage.k8s.io/v1alpha1 because it has no resources.1027machine # [ 26.560591] k3s[815]: I0827 17:07:50.267762 815 handler.go:304] Adding GroupVersion flowcontrol.apiserver.k8s.io v1 to ResourceManager1028machine # [ 26.562375] k3s[815]: W0827 17:07:50.267789 815 genericapiserver.go:787] Skipping API flowcontrol.apiserver.k8s.io/v1beta3 because it has no resources.1029machine # [ 26.564424] k3s[815]: W0827 17:07:50.267797 815 genericapiserver.go:787] Skipping API flowcontrol.apiserver.k8s.io/v1beta2 because it has no resources.1030machine # [ 26.566348] k3s[815]: W0827 17:07:50.267803 815 genericapiserver.go:787] Skipping API flowcontrol.apiserver.k8s.io/v1beta1 because it has no resources.1031machine # [ 26.568283] k3s[815]: I0827 17:07:50.272120 815 handler.go:304] Adding GroupVersion apps v1 to ResourceManager1032machine # [ 26.569820] k3s[815]: W0827 17:07:50.272165 815 genericapiserver.go:787] Skipping API apps/v1beta2 because it has no resources.1033machine # [ 26.571325] k3s[815]: W0827 17:07:50.272174 815 genericapiserver.go:787] Skipping API apps/v1beta1 because it has no resources.1034machine # [ 26.573003] k3s[815]: I0827 17:07:50.274482 815 handler.go:304] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager1035machine # [ 26.574715] k3s[815]: W0827 17:07:50.274530 815 genericapiserver.go:787] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.1036machine # [ 26.576656] k3s[815]: W0827 17:07:50.274541 815 genericapiserver.go:787] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources.1037machine # [ 26.578545] k3s[815]: I0827 17:07:50.275381 815 handler.go:304] Adding GroupVersion events.k8s.io v1 to ResourceManager1038machine # [ 26.580166] k3s[815]: W0827 17:07:50.275406 815 genericapiserver.go:787] Skipping API events.k8s.io/v1beta1 because it has no resources.1039machine # [ 26.581913] k3s[815]: I0827 17:07:50.278093 815 handler.go:304] Adding GroupVersion resource.k8s.io v1 to ResourceManager1040machine # [ 26.583489] k3s[815]: W0827 17:07:50.278128 815 genericapiserver.go:787] Skipping API resource.k8s.io/v1beta2 because it has no resources.1041machine # [ 26.585339] k3s[815]: W0827 17:07:50.278136 815 genericapiserver.go:787] Skipping API resource.k8s.io/v1beta1 because it has no resources.1042machine # [ 26.587094] k3s[815]: W0827 17:07:50.278140 815 genericapiserver.go:787] Skipping API resource.k8s.io/v1alpha3 because it has no resources.1043machine # [ 26.589012] k3s[815]: I0827 17:07:50.286131 815 handler.go:304] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager1044machine # [ 26.590775] k3s[815]: W0827 17:07:50.286182 815 genericapiserver.go:787] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.1045machine # [ 27.101432] k3s[815]: time="2026-08-27T17:07:50Z" level=info msg="containerd is now running"1046machine # [ 27.111686] k3s[815]: time="2026-08-27T17:07:50Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-arm64.tar.zst"1047machine # [ 27.137592] k3s[815]: I0827 17:07:50.894892 815 secure_serving.go:211] Serving securely on 127.0.0.1:64441048machine # [ 27.142020] k3s[815]: I0827 17:07:50.895653 815 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"1049machine # [ 27.147442] k3s[815]: I0827 17:07:50.896634 815 tlsconfig.go:243] "Starting DynamicServingCertificateController"1050machine # [ 27.150040] k3s[815]: I0827 17:07:50.897466 815 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1051machine # [ 27.156319] k3s[815]: I0827 17:07:50.897924 815 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1052machine # [ 27.158452] k3s[815]: time="2026-08-27T17:07:50Z" level=info msg="Starting apiserver lease garbage collector" logger=k3s1053machine # [ 27.159955] k3s[815]: time="2026-08-27T17:07:50Z" level=info msg="Waiting for caches to sync" logger=k3s1054machine # [ 27.164221] k3s[815]: I0827 17:07:50.899174 815 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"1055machine # [ 27.167203] k3s[815]: I0827 17:07:50.900888 815 cluster_authentication_trust_controller.go:459] Starting cluster_authentication_trust_controller controller1056machine # [ 27.172186] k3s[815]: time="2026-08-27T17:07:50Z" level=info msg="Waiting for caches to sync" logger=k3s1057machine # [ 27.173824] k3s[815]: I0827 17:07:50.901007 815 system_namespaces_controller.go:66] Starting system namespaces controller1058machine # [ 27.175633] k3s[815]: I0827 17:07:50.901355 815 controller.go:113] "Deleting old lease on startup" lease="kube-system/apiserver-ik4pcwfs7qgdl76byc4pomgvia"1059machine # [ 27.180194] k3s[815]: I0827 17:07:50.903368 815 aggregator.go:185] waiting for initial CRD sync...1060machine # [ 27.181700] k3s[815]: I0827 17:07:50.903421 815 controller.go:80] Starting OpenAPI V3 AggregationController1061machine # [ 27.183128] k3s[815]: I0827 17:07:50.903800 815 apf_controller.go:377] Starting API Priority and Fairness config controller1062machine # [ 27.188240] k3s[815]: I0827 17:07:50.904526 815 apiservice_controller.go:100] Starting APIServiceRegistrationController1063machine # [ 27.189909] k3s[815]: I0827 17:07:50.904554 815 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller1064machine # [ 27.191640] k3s[815]: I0827 17:07:50.905361 815 controller.go:78] Starting OpenAPI AggregationController1065machine # [ 27.193137] k3s[815]: I0827 17:07:50.907556 815 customresource_discovery_controller.go:294] Starting DiscoveryController1066machine # [ 27.194691] k3s[815]: I0827 17:07:50.908642 815 local_available_controller.go:156] Starting LocalAvailability controller1067machine # [ 27.200265] k3s[815]: I0827 17:07:50.908668 815 cache.go:32] Waiting for caches to sync for LocalAvailability controller1068machine # [ 27.201947] k3s[815]: I0827 17:07:50.908714 815 remote_available_controller.go:425] Starting RemoteAvailability controller1069machine # [ 27.203541] k3s[815]: I0827 17:07:50.908721 815 cache.go:32] Waiting for caches to sync for RemoteAvailability controller1070machine # [ 27.205179] k3s[815]: time="2026-08-27T17:07:50Z" level=info msg="Starting legacy_token_tracking_controller" logger=k3s1071machine # [ 27.206600] k3s[815]: time="2026-08-27T17:07:50Z" level=info msg="Waiting for caches to sync" logger=k3s1072machine # [ 27.207859] k3s[815]: I0827 17:07:50.943245 815 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1073machine # [ 27.209956] k3s[815]: I0827 17:07:50.943396 815 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1074machine # [ 27.211950] k3s[815]: I0827 17:07:50.943715 815 crdregistration_controller.go:114] Starting crd-autoregister controller1075machine # [ 27.216227] k3s[815]: I0827 17:07:50.943732 815 shared_informer.go:349] "Waiting for caches to sync" controller="crd-autoregister"1076machine # [ 27.217934] k3s[815]: I0827 17:07:50.943811 815 repairip.go:210] Starting ipallocator-repair-controller1077machine # [ 27.219252] k3s[815]: I0827 17:07:50.943822 815 shared_informer.go:349] "Waiting for caches to sync" controller="ipallocator-repair-controller"1078machine # [ 27.224239] k3s[815]: I0827 17:07:50.944255 815 default_servicecidr_controller.go:110] Starting kubernetes-service-cidr-controller1079machine # [ 27.226009] k3s[815]: I0827 17:07:50.944275 815 shared_informer.go:349] "Waiting for caches to sync" controller="kubernetes-service-cidr-controller"1080machine # [ 27.227869] k3s[815]: I0827 17:07:50.944424 815 controller.go:142] Starting OpenAPI controller1081machine # [ 27.229308] k3s[815]: I0827 17:07:50.944463 815 controller.go:90] Starting OpenAPI V3 controller1082machine # [ 27.230584] k3s[815]: I0827 17:07:50.944489 815 naming_controller.go:305] Starting NamingConditionController1083machine # [ 27.231997] k3s[815]: I0827 17:07:50.944546 815 nonstructuralschema_controller.go:202] Starting NonStructuralSchemaConditionController1084machine # [ 27.237951] k3s[815]: I0827 17:07:50.944564 815 apiapproval_controller.go:196] Starting KubernetesAPIApprovalPolicyConformantConditionController1085machine # [ 27.239805] k3s[815]: I0827 17:07:50.944581 815 crd_finalizer.go:273] Starting CRDFinalizer1086machine # [ 27.324623] k3s[815]: I0827 17:07:51.081964 815 shared_informer.go:356] "Caches are synced" controller="node_authorizer"1087machine # [ 27.331314] k3s[815]: I0827 17:07:51.088672 815 shared_informer.go:377] "Caches are synced"1088machine # [ 27.333963] k3s[815]: I0827 17:07:51.088732 815 policy_source.go:248] refreshing policies1089machine # [ 27.347445] k3s[815]: I0827 17:07:51.104533 815 controller.go:667] quota admission added evaluator for: namespaces1090machine # [ 27.349571] k3s[815]: I0827 17:07:51.104639 815 apf_controller.go:382] Running API Priority and Fairness config worker1091machine # [ 27.351308] k3s[815]: I0827 17:07:51.104650 815 apf_controller.go:385] Running API Priority and Fairness periodic rebalancing process1092machine # [ 27.353875] k3s[815]: I0827 17:07:51.105365 815 cache.go:39] Caches are synced for APIServiceRegistrationController controller1093machine # [ 27.355721] k3s[815]: I0827 17:07:51.105932 815 handler_discovery.go:451] Starting ResourceDiscoveryManager1094machine # [ 27.357574] k3s[815]: I0827 17:07:51.109987 815 cache.go:39] Caches are synced for LocalAvailability controller1095machine # [ 27.359094] k3s[815]: time="2026-08-27T17:07:51Z" level=info msg="Caches are synced" logger=k3s1096machine # [ 27.360780] k3s[815]: I0827 17:07:51.115843 815 controller.go:667] quota admission added evaluator for: leases.coordination.k8s.io1097machine # [ 27.388191] k3s[815]: I0827 17:07:51.143827 815 shared_informer.go:356] "Caches are synced" controller="crd-autoregister"1098machine # [ 27.389961] k3s[815]: I0827 17:07:51.144319 815 shared_informer.go:356] "Caches are synced" controller="kubernetes-service-cidr-controller"1099machine # [ 27.391764] k3s[815]: I0827 17:07:51.144374 815 default_servicecidr_controller.go:169] Creating default ServiceCIDR with CIDRs: [10.43.0.0/16]1100machine # [ 27.396228] k3s[815]: I0827 17:07:51.144652 815 aggregator.go:187] initial CRD sync complete...1101machine # [ 27.397607] k3s[815]: I0827 17:07:51.144668 815 autoregister_controller.go:144] Starting autoregister controller1102machine # [ 27.399059] k3s[815]: I0827 17:07:51.144680 815 cache.go:32] Waiting for caches to sync for autoregister controller1103machine # [ 27.400598] k3s[815]: I0827 17:07:51.144690 815 cache.go:39] Caches are synced for autoregister controller1104machine # [ 27.411584] k3s[815]: I0827 17:07:51.168920 815 cidrallocator.go:302] created ClusterIP allocator for Service CIDR 10.43.0.0/161105machine # [ 27.414878] k3s[815]: I0827 17:07:51.172276 815 default_servicecidr_controller.go:231] Setting default ServiceCIDR condition Ready to True1106machine # [ 27.431552] k3s[815]: I0827 17:07:51.188139 815 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161107machine # [ 27.446662] k3s[815]: I0827 17:07:51.193306 815 default_servicecidr_controller.go:231] Setting default ServiceCIDR condition Ready to True1108machine # [ 27.448507] k3s[815]: time="2026-08-27T17:07:51Z" level=info msg="Caches are synced" logger=k3s1109machine # [ 27.449948] k3s[815]: time="2026-08-27T17:07:51Z" level=info msg="Caches are synced" logger=k3s1110machine # [ 27.466913] k3s[815]: I0827 17:07:51.223526 815 cache.go:39] Caches are synced for RemoteAvailability controller1111machine # [ 27.473153] k3s[815]: I0827 17:07:51.230500 815 alloc.go:329] "allocated clusterIPs" service="default/kubernetes" clusterIPs={"IPv4":"10.43.0.1"}1112machine # [ 27.488653] k3s[815]: I0827 17:07:51.244323 815 shared_informer.go:356] "Caches are synced" controller="ipallocator-repair-controller"1113machine # [ 27.501579] k3s[815]: W0827 17:07:51.258006 815 lease.go:265] Resetting endpoints for master service "kubernetes" to [10.0.2.15]1114machine # [ 27.504316] k3s[815]: I0827 17:07:51.261580 815 controller.go:667] quota admission added evaluator for: endpoints1115machine # [ 27.528987] k3s[815]: I0827 17:07:51.281623 815 controller.go:667] quota admission added evaluator for: endpointslices.discovery.k8s.io1116machine # [ 27.549778] k3s[815]: E0827 17:07:51.307133 815 controller.go:102] Error removing old endpoints from kubernetes service: no API server IP addresses were listed in storage, refusing to erase all endpoints for the kubernetes Service1117machine # [ 27.925083] k3s[815]: time="2026-08-27T17:07:51Z" level=info msg="Polling for API server readiness: GET /readyz failed: unknown"1118machine # [ 28.149936] k3s[815]: I0827 17:07:51.907232 815 storage_scheduling.go:123] created PriorityClass system-node-critical with value 20000010001119machine # [ 28.160594] k3s[815]: I0827 17:07:51.917890 815 storage_scheduling.go:123] created PriorityClass system-cluster-critical with value 20000000001120machine # [ 28.162877] k3s[815]: I0827 17:07:51.917988 815 storage_scheduling.go:139] all system priority classes are created successfully or already exist.1121machine # [ 29.612612] k3s[815]: I0827 17:07:53.369414 815 controller.go:667] quota admission added evaluator for: roles.rbac.authorization.k8s.io1122machine # [ 29.689848] k3s[815]: I0827 17:07:53.447176 815 controller.go:667] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io1123machine # [ 29.927573] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Creating k3s-supervisor event broadcaster"1124machine # [ 29.930577] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Kube API server is now running"1125machine # [ 29.932613] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="k3s is up and running"1126machine # [ 29.936607] systemd[1]: Started k3s service.1127machine # [ 29.937379] systemd[1]: Reached target Multi-User System.1128machine # [ 29.938176] systemd[1]: Startup finished in 811ms (kernel) + 5.781s (initrd) + 23.336s (userspace) = 29.930s.1129machine # [ 29.939521] k3s[815]: time="2026-08-27T17:07:53Z" 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=Normal1130machine # [ 29.942598] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Waiting for untainted node"1131machine # [ 29.977637] k3s[815]: I0827 17:07:53.734891 815 controllermanager.go:189] "Starting" version="v1.35.7+k3s1"1132machine # [ 29.979814] k3s[815]: I0827 17:07:53.734936 815 controllermanager.go:191] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1133machine # [ 29.982630] k3s[815]: I0827 17:07:53.738986 815 secure_serving.go:211] Serving securely on 127.0.0.1:102571134machine # [ 29.985290] k3s[815]: I0827 17:07:53.739709 815 tlsconfig.go:243] "Starting DynamicServingCertificateController"1135machine # [ 29.987593] k3s[815]: I0827 17:07:53.739774 815 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1136machine # [ 29.992968] k3s[815]: I0827 17:07:53.739798 815 shared_informer.go:370] "Waiting for caches to sync"1137machine # [ 29.996800] k3s[815]: I0827 17:07:53.739825 815 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"1138machine # [ 30.008228] k3s[815]: I0827 17:07:53.739968 815 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1139machine # [ 30.014285] k3s[815]: I0827 17:07:53.740001 815 shared_informer.go:370] "Waiting for caches to sync"1140machine # [ 30.016075] k3s[815]: I0827 17:07:53.740015 815 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1141machine # [ 30.019274] k3s[815]: I0827 17:07:53.740030 815 shared_informer.go:370] "Waiting for caches to sync"1142machine # [ 30.021333] k3s[815]: I0827 17:07:53.765643 815 controller.go:667] quota admission added evaluator for: serviceaccounts1143machine # [ 30.032509] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Creating embedded CRD etcdsnapshotfiles.k3s.cattle.io"1144machine # [ 30.046505] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Creating embedded CRD addons.k3s.cattle.io"1145machine # [ 30.076100] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Creating embedded CRD helmchartconfigs.helm.cattle.io"1146machine # [ 30.087484] k3s[815]: I0827 17:07:53.844858 815 shared_informer.go:377] "Caches are synced"1147machine # [ 30.090000] k3s[815]: I0827 17:07:53.847234 815 shared_informer.go:377] "Caches are synced"1148machine # [ 30.095421] k3s[815]: I0827 17:07:53.847549 815 shared_informer.go:377] "Caches are synced"1149machine # [ 30.107156] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Creating embedded CRD helmcharts.helm.cattle.io"1150machine # [ 30.119862] k3s[815]: I0827 17:07:53.877146 815 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1151machine # [ 30.151792] k3s[815]: I0827 17:07:53.909097 815 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1152machine # [ 30.160087] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Waiting for CRD helmchartconfigs.helm.cattle.io to become available"1153machine # [ 30.184185] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Done waiting for CRD helmchartconfigs.helm.cattle.io to become available"1154machine # [ 30.186027] k3s[815]: time="2026-08-27T17:07:53Z" level=info msg="Waiting for CRD helmcharts.helm.cattle.io to become available"1155machine # [ 30.198294] k3s[815]: I0827 17:07:53.955671 815 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1156machine # [ 30.204389] k3s[815]: I0827 17:07:53.960787 815 shared_informer.go:370] "Waiting for caches to sync"1157machine # [ 30.225043] k3s[815]: I0827 17:07:53.982428 815 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1158machine # [ 30.255471] k3s[815]: I0827 17:07:54.012836 815 node_lifecycle_controller.go:419] "Controller will reconcile labels" logger="node-lifecycle-controller"1159machine # [ 30.271204] k3s[815]: I0827 17:07:54.028544 815 controllermanager.go:627] "Warning: controller is disabled" controller="cloud-node-lifecycle-controller"1160machine # [ 30.274906] k3s[815]: I0827 17:07:54.028597 815 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller" requiredFeatureGates=["ClusterTrustBundle"]1161machine # [ 30.278076] k3s[815]: I0827 17:07:54.028647 815 controllermanager.go:579] "Warning: skipping controller" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller"1162machine # [ 30.306191] k3s[815]: I0827 17:07:54.063443 815 shared_informer.go:377] "Caches are synced"1163machine # [ 30.704243] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Done waiting for CRD helmcharts.helm.cattle.io to become available"1164machine # [ 30.706947] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-40.1.4+up40.1.0.tgz"1165machine # [ 30.710649] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-40.1.4+up40.1.0.tgz"1166machine # [ 30.714356] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml"1167machine # [ 30.717406] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml"1168machine # [ 30.719228] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml"1169machine # [ 30.721433] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml"1170machine # [ 30.723550] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/runtimes.yaml"1171machine # [ 30.726078] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml"1172machine: (finished: waiting for unit k3s.service, in 31.63 seconds)1173machine: waiting for unit rustfs-setup.service1174machine: (finished: waiting for unit rustfs-setup.service, in 0.07 seconds)1175machine: waiting for unit postgresql.service1176machine # [ 30.911625] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Starting dynamiclistener CN filter node controller with SANs: [127.0.0.1 ::1 localhost machine 10.0.2.15 fec0::55d6:1ccb:f2c5:cfd8 10.43.0.1 kubernetes kubernetes.default kubernetes.default.svc kubernetes.default.svc.cluster.local]"1177machine # [ 30.917970] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Tunnel server egress proxy mode: agent"1178machine # [ 30.919638] k3s[815]: I0827 17:07:54.669283 815 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podcertificaterequest-cleaner-controller" requiredFeatureGates=["PodCertificateRequest"]1179machine # [ 30.922744] k3s[815]: I0827 17:07:54.669311 815 controllermanager.go:579] "Warning: skipping controller" controller="podcertificaterequest-cleaner-controller"1180machine # [ 30.925180] k3s[815]: I0827 17:07:54.669321 815 controllermanager.go:627] "Warning: controller is disabled" controller="bootstrap-signer-controller"1181machine # [ 31.009688] k3s[815]: time="2026-08-27T17:07:54Z" 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__55d6_1ccb_f2c5_cfd8-a95230:fec0::55d6:1ccb:f2c5:cfd8 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=7B63E4D2B883A0A342925D6935FE6FFA00D2FAF7]"1182machine # [ 31.025176] k3s[815]: time="2026-08-27T17:07:54Z" level=info msg="Active TLS secret kube-system/k3s-serving (ver=235) (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__55d6_1ccb_f2c5_cfd8-a95230:fec0::55d6:1ccb:f2c5:cfd8 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=7B63E4D2B883A0A342925D6935FE6FFA00D2FAF7]"1183machine # [ 31.053222] k3s[815]: I0827 17:07:54.810445 815 controllermanager.go:627] "Warning: controller is disabled" controller="service-lb-controller"1184machine: (finished: waiting for unit postgresql.service, in 0.18 seconds)1185subtest: chart deploys and becomes ready1186??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1187 File "/nix/store/crl2fqhqr147kjv2qkfdwrz8hsxzd6zz-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391188machine: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s1189??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1190 File "/nix/store/crl2fqhqr147kjv2qkfdwrz8hsxzd6zz-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391191machine # Error from server (NotFound): namespaces "niks3" not found1192machine # [ 32.026426] k3s[815]: time="2026-08-27T17:07:55Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller"1193machine # [ 32.028258] k3s[815]: time="2026-08-27T17:07:55Z" level=info msg="Creating deploy event broadcaster"1194machine # [ 32.035071] k3s[815]: time="2026-08-27T17:07:55Z" level=info msg="Creating helm-controller event broadcaster"1195machine # [ 32.037215] k3s[815]: time="2026-08-27T17:07:55Z" level=info msg="Starting /v1, Kind=Node controller"1196machine # [ 32.043155] k3s[815]: I0827 17:07:55.800352 815 controller.go:667] quota admission added evaluator for: addons.k3s.cattle.io1197machine # [ 32.061223] k3s[815]: time="2026-08-27T17:07:55Z" level=info msg="Unable to set control-plane role label: nodes \"machine\" not found"1198machine # [ 32.084210] k3s[815]: time="2026-08-27T17:07:55Z" 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=Normal1199machine # [ 32.095625] k3s[815]: time="2026-08-27T17:07:55Z" level=info msg="Cluster dns configmap has been set successfully"1200machine # [ 32.160180] k3s[815]: I0827 17:07:55.916254 815 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="device-taint-eviction-controller" requiredFeatureGates=["DynamicResourceAllocation","DRADeviceTaints"]1201machine # [ 32.163270] k3s[815]: I0827 17:07:55.916317 815 controllermanager.go:579] "Warning: skipping controller" controller="device-taint-eviction-controller"1202machine # [ 32.673790] k3s[815]: I0827 17:07:56.431121 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="addons.k3s.cattle.io"1203machine # [ 32.678327] k3s[815]: I0827 17:07:56.433980 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="limitranges"1204machine # [ 32.681296] k3s[815]: I0827 17:07:56.434053 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="roles.rbac.authorization.k8s.io"1205machine # [ 32.684225] k3s[815]: I0827 17:07:56.434086 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="controllerrevisions.apps"1206machine # [ 32.690745] k3s[815]: I0827 17:07:56.434138 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="daemonsets.apps"1207machine # [ 32.693013] k3s[815]: I0827 17:07:56.434183 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="networkpolicies.networking.k8s.io"1208machine # [ 32.695439] k3s[815]: I0827 17:07:56.434207 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="rolebindings.rbac.authorization.k8s.io"1209machine # [ 32.699074] k3s[815]: I0827 17:07:56.434240 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="resourceclaimtemplates.resource.k8s.io"1210machine # [ 32.704804] k3s[815]: I0827 17:07:56.434296 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmcharts.helm.cattle.io"1211machine # [ 32.708151] k3s[815]: I0827 17:07:56.434345 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="podtemplates"1212machine # [ 32.711104] k3s[815]: I0827 17:07:56.434398 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="horizontalpodautoscalers.autoscaling"1213machine # [ 32.713857] k3s[815]: I0827 17:07:56.434433 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="csistoragecapacities.storage.k8s.io"1214machine # [ 32.716321] k3s[815]: I0827 17:07:56.434459 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="leases.coordination.k8s.io"1215machine # [ 32.721885] k3s[815]: I0827 17:07:56.434500 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="deployments.apps"1216machine # [ 32.725058] k3s[815]: I0827 17:07:56.434520 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpoints"1217machine # [ 32.727904] k3s[815]: I0827 17:07:56.434538 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="cronjobs.batch"1218machine # [ 32.731800] k3s[815]: I0827 17:07:56.434553 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="serviceaccounts"1219machine # [ 32.735887] k3s[815]: I0827 17:07:56.434568 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="statefulsets.apps"1220machine # Error from server (NotFound): namespaces "niks3" not found1221machine # [ 32.740199] k3s[815]: I0827 17:07:56.434586 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="jobs.batch"1222machine # [ 32.742457] k3s[815]: I0827 17:07:56.434617 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="ingresses.networking.k8s.io"1223machine # [ 32.745045] k3s[815]: I0827 17:07:56.434639 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="poddisruptionbudgets.policy"1224machine # [ 32.747396] k3s[815]: I0827 17:07:56.434662 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmchartconfigs.helm.cattle.io"1225machine # [ 32.749859] k3s[815]: I0827 17:07:56.434689 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="replicasets.apps"1226machine # [ 32.753747] k3s[815]: I0827 17:07:56.434709 815 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpointslices.discovery.k8s.io"1227machine # [ 32.763498] k3s[815]: time="2026-08-27T17:07:56Z" 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=Normal1228machine # [ 32.785982] k3s[815]: time="2026-08-27T17:07:56Z" 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=Normal1229machine # [ 32.797574] k3s[815]: I0827 17:07:56.554917 815 controllermanager.go:627] "Warning: controller is disabled" controller="node-route-controller"1230machine # [ 32.968910] k3s[815]: W0827 17:07:56.726208 815 probe.go:272] Flexvolume plugin directory at /usr/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating.1231machine # [ 33.064639] k3s[815]: time="2026-08-27T17:07:56Z" level=info msg="Unable to set control-plane role label: nodes \"machine\" not found"1232machine # [ 33.066417] k3s[815]: time="2026-08-27T17:07:56Z" 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=Normal1233machine # [ 33.104469] k3s[815]: time="2026-08-27T17:07:56Z" 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=Normal1234machine # [ 33.296061] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller"1235machine # [ 33.305483] k3s[815]: I0827 17:07:57.062881 815 serving.go:392] Generated self-signed cert in-memory1236machine # [ 33.330278] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting batch/v1, Kind=Job controller"1237machine # [ 33.333121] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting /v1, Kind=Secret controller"1238machine # [ 33.334380] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting /v1, Kind=ConfigMap controller"1239machine # [ 33.335644] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting /v1, Kind=ServiceAccount controller"1240machine # [ 33.352566] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller"1241machine # [ 33.354493] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller"1242machine # [ 33.406343] k3s[815]: I0827 17:07:57.162878 815 serving.go:392] Generated self-signed cert in-memory1243machine # [ 33.588268] k3s[815]: I0827 17:07:57.344811 815 controllermanager.go:160] Version: v1.35.7+k3s11244machine # [ 33.592150] k3s[815]: I0827 17:07:57.348843 815 secure_serving.go:211] Serving securely on 127.0.0.1:102581245machine # [ 33.593825] k3s[815]: I0827 17:07:57.349787 815 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1246machine # [ 33.595459] k3s[815]: I0827 17:07:57.349820 815 shared_informer.go:370] "Waiting for caches to sync"1247machine # [ 33.596928] k3s[815]: I0827 17:07:57.349855 815 tlsconfig.go:243] "Starting DynamicServingCertificateController"1248machine # [ 33.598373] k3s[815]: I0827 17:07:57.349961 815 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1249machine # [ 33.601903] k3s[815]: I0827 17:07:57.349979 815 shared_informer.go:370] "Waiting for caches to sync"1250machine # [ 33.603766] k3s[815]: I0827 17:07:57.350002 815 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1251machine # [ 33.606861] k3s[815]: I0827 17:07:57.350018 815 shared_informer.go:370] "Waiting for caches to sync"1252machine # [ 33.608881] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Creating service-lb-controller event broadcaster"1253machine # [ 33.940628] k3s[815]: I0827 17:07:57.695809 815 range_allocator.go:113] "No Secondary Service CIDR provided. Skipping filtering out secondary service addresses" logger="node-ipam-controller"1254machine # [ 33.993177] k3s[815]: I0827 17:07:57.750460 815 shared_informer.go:377] "Caches are synced"1255machine # [ 33.997702] k3s[815]: I0827 17:07:57.750615 815 shared_informer.go:377] "Caches are synced"1256machine # [ 34.001149] k3s[815]: I0827 17:07:57.750751 815 shared_informer.go:377] "Caches are synced"1257machine # [ 34.040272] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Unable to set control-plane role label: nodes \"machine\" not found"1258machine # [ 34.050036] k3s[815]: I0827 17:07:57.807402 815 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="storageversion-garbage-collector-controller" requiredFeatureGates=["APIServerIdentity","StorageVersionAPI"]1259machine # [ 34.053900] k3s[815]: I0827 17:07:57.810664 815 controllermanager.go:579] "Warning: skipping controller" controller="storageversion-garbage-collector-controller"1260machine # Error from server (NotFound): namespaces "niks3" not found1261machine # [ 34.155137] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting /v1, Kind=Node controller"1262machine # [ 34.159191] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting /v1, Kind=Pod controller"1263machine # [ 34.167573] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller"1264machine # [ 34.170212] k3s[815]: I0827 17:07:57.927571 815 controllermanager.go:329] Started "cloud-node-controller"1265machine # [ 34.171699] k3s[815]: I0827 17:07:57.927865 815 controllermanager.go:329] Started "cloud-node-lifecycle-controller"1266machine # [ 34.173739] k3s[815]: I0827 17:07:57.928271 815 controllermanager.go:329] Started "service-lb-controller"1267machine # [ 34.175335] k3s[815]: W0827 17:07:57.928290 815 controllermanager.go:306] "node-route-controller" is disabled1268machine # [ 34.177367] k3s[815]: time="2026-08-27T17:07:57Z" level=info msg="Starting discovery.k8s.io/v1, Kind=EndpointSlice controller"1269machine # [ 34.179266] k3s[815]: I0827 17:07:57.929219 815 node_controller.go:176] Sending events to api server.1270machine # [ 34.181023] k3s[815]: I0827 17:07:57.929267 815 node_lifecycle_controller.go:112] Sending events to api server1271machine # [ 34.182757] k3s[815]: I0827 17:07:57.929345 815 node_controller.go:185] Waiting for informer caches to sync1272machine # [ 34.184459] k3s[815]: I0827 17:07:57.929452 815 controller.go:235] Starting service controller1273machine # [ 34.187108] k3s[815]: I0827 17:07:57.929527 815 shared_informer.go:370] "Waiting for caches to sync"1274machine # [ 34.206241] k3s[815]: I0827 17:07:57.963506 815 controller.go:667] quota admission added evaluator for: deployments.apps1275machine # [ 34.248349] k3s[815]: I0827 17:07:58.005719 815 controllermanager.go:579] "Warning: skipping controller" controller="storage-version-migrator-controller"1276machine # [ 34.251017] k3s[815]: I0827 17:07:58.005753 815 controllermanager.go:627] "Warning: controller is disabled" controller="selinux-warning-controller"1277machine # [ 34.411385] k3s[815]: I0827 17:07:58.168706 815 alloc.go:329] "allocated clusterIPs" service="kube-system/kube-dns" clusterIPs={"IPv4":"10.43.0.10"}1278machine # [ 34.416251] k3s[815]: time="2026-08-27T17:07:58Z" 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=Normal1279machine # [ 34.473161] k3s[815]: I0827 17:07:58.230264 815 shared_informer.go:377] "Caches are synced"1280machine # [ 34.555488] k3s[815]: I0827 17:07:58.312812 815 pv_controller_base.go:307] "Starting persistent volume controller"1281machine # [ 34.557431] k3s[815]: I0827 17:07:58.312856 815 shared_informer.go:370] "Waiting for caches to sync"1282machine # [ 34.564209] k3s[815]: I0827 17:07:58.317663 815 shared_informer.go:370] "Waiting for caches to sync"1283machine # [ 34.565733] k3s[815]: I0827 17:07:58.317725 815 vac_protection_controller.go:206] "Starting VAC protection controller"1284machine # [ 34.567274] k3s[815]: I0827 17:07:58.317738 815 shared_informer.go:370] "Waiting for caches to sync"1285machine # [ 34.568680] k3s[815]: I0827 17:07:58.317828 815 replica_set.go:241] "Starting controller" name="replicationcontroller"1286machine # [ 34.570196] k3s[815]: I0827 17:07:58.317841 815 shared_informer.go:370] "Waiting for caches to sync"1287machine # [ 34.571721] k3s[815]: I0827 17:07:58.317869 815 namespace_controller.go:202] "Starting namespace controller"1288machine # [ 34.573448] k3s[815]: I0827 17:07:58.317879 815 shared_informer.go:370] "Waiting for caches to sync"1289machine # [ 34.574852] k3s[815]: I0827 17:07:58.317897 815 serviceaccounts_controller.go:117] "Starting service account controller"1290machine # [ 34.576516] k3s[815]: I0827 17:07:58.317907 815 shared_informer.go:370] "Waiting for caches to sync"1291machine # [ 34.577917] k3s[815]: I0827 17:07:58.317953 815 daemon_controller.go:309] "Starting daemon sets controller"1292machine # [ 34.579375] k3s[815]: I0827 17:07:58.317963 815 shared_informer.go:370] "Waiting for caches to sync"1293machine # [ 34.580923] k3s[815]: I0827 17:07:58.317993 815 disruption.go:458] "Sending events to api server."1294machine # [ 34.582346] k3s[815]: I0827 17:07:58.318019 815 disruption.go:465] "Starting disruption controller"1295machine # [ 34.583672] k3s[815]: I0827 17:07:58.318028 815 shared_informer.go:370] "Waiting for caches to sync"1296machine # [ 34.585163] k3s[815]: I0827 17:07:58.318068 815 ttl_controller.go:127] "Starting TTL controller"1297machine # [ 34.586417] k3s[815]: I0827 17:07:58.318078 815 shared_informer.go:370] "Waiting for caches to sync"1298machine # [ 34.587734] k3s[815]: I0827 17:07:58.318110 815 node_lifecycle_controller.go:453] "Sending events to api server"1299machine # [ 34.589293] k3s[815]: I0827 17:07:58.318137 815 node_lifecycle_controller.go:460] "Starting node controller"1300machine # [ 34.590827] k3s[815]: I0827 17:07:58.318146 815 shared_informer.go:370] "Waiting for caches to sync"1301machine # [ 34.592284] k3s[815]: I0827 17:07:58.318279 815 legacy_serviceaccount_token_cleaner.go:103] "Starting legacy service account token cleaner controller"1302machine # [ 34.594138] k3s[815]: I0827 17:07:58.318293 815 shared_informer.go:370] "Waiting for caches to sync"1303machine # [ 34.595443] k3s[815]: I0827 17:07:58.318331 815 taint_eviction.go:283] "Starting" controller="taint-eviction-controller"1304machine # [ 34.597037] k3s[815]: I0827 17:07:58.318370 815 taint_eviction.go:288] "Sending events to API server"1305machine # [ 34.598335] k3s[815]: I0827 17:07:58.318930 815 shared_informer.go:370] "Waiting for caches to sync"1306machine # [ 34.599634] k3s[815]: I0827 17:07:58.319044 815 servicecidrs_controller.go:136] "Starting" controller="service-cidr-controller"1307machine # [ 34.601602] k3s[815]: I0827 17:07:58.319063 815 shared_informer.go:370] "Waiting for caches to sync"1308machine # [ 34.603029] k3s[815]: I0827 17:07:58.319133 815 endpoints_controller.go:193] "Starting endpoint controller"1309machine # [ 34.604579] k3s[815]: I0827 17:07:58.319144 815 shared_informer.go:370] "Waiting for caches to sync"1310machine # [ 34.606023] k3s[815]: I0827 17:07:58.319206 815 endpointslicemirroring_controller.go:226] "Starting EndpointSliceMirroring controller"1311machine # [ 34.607842] k3s[815]: I0827 17:07:58.319219 815 shared_informer.go:370] "Waiting for caches to sync"1312machine # [ 34.609423] k3s[815]: I0827 17:07:58.319267 815 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-legacy-unknown"1313machine # [ 34.611397] k3s[815]: I0827 17:07:58.319278 815 shared_informer.go:370] "Waiting for caches to sync"1314machine # [ 34.612885] k3s[815]: I0827 17:07:58.319298 815 tokencleaner.go:117] "Starting token cleaner controller"1315machine # [ 34.614360] k3s[815]: I0827 17:07:58.319309 815 shared_informer.go:370] "Waiting for caches to sync"1316machine # [ 34.615677] k3s[815]: I0827 17:07:58.319331 815 clusterroleaggregation_controller.go:194] "Starting ClusterRoleAggregator controller"1317machine # [ 34.617461] k3s[815]: I0827 17:07:58.319343 815 shared_informer.go:370] "Waiting for caches to sync"1318machine # [ 34.618743] k3s[815]: I0827 17:07:58.319377 815 gc_controller.go:98] "Starting GC controller"1319machine # [ 34.619937] k3s[815]: I0827 17:07:58.319388 815 shared_informer.go:370] "Waiting for caches to sync"1320machine # [ 34.621481] k3s[815]: I0827 17:07:58.319435 815 cronjob_controllerv2.go:143] "Starting cronjob controller v2"1321machine # [ 34.622848] k3s[815]: I0827 17:07:58.319446 815 shared_informer.go:370] "Waiting for caches to sync"1322machine # [ 34.624149] k3s[815]: I0827 17:07:58.319463 815 certificate_controller.go:120] "Starting certificate controller" name="csrapproving"1323machine # [ 34.625761] k3s[815]: I0827 17:07:58.319473 815 shared_informer.go:370] "Waiting for caches to sync"1324machine # [ 34.627007] k3s[815]: I0827 17:07:58.319500 815 expand_controller.go:328] "Starting expand controller"1325machine # [ 34.628283] k3s[815]: I0827 17:07:58.319510 815 shared_informer.go:370] "Waiting for caches to sync"1326machine # [ 34.629498] k3s[815]: I0827 17:07:58.319528 815 pv_protection_controller.go:81] "Starting PV protection controller"1327machine # [ 34.630868] k3s[815]: I0827 17:07:58.319540 815 shared_informer.go:370] "Waiting for caches to sync"1328machine # [ 34.632228] k3s[815]: I0827 17:07:58.319584 815 publisher.go:107] "Starting root CA cert publisher controller"1329machine # [ 34.633702] k3s[815]: I0827 17:07:58.319593 815 shared_informer.go:370] "Waiting for caches to sync"1330machine # [ 34.635038] k3s[815]: I0827 17:07:58.319622 815 controller.go:174] "Starting ephemeral volume controller"1331machine # [ 34.636462] k3s[815]: I0827 17:07:58.319636 815 shared_informer.go:370] "Waiting for caches to sync"1332machine # [ 34.637764] k3s[815]: I0827 17:07:58.319679 815 endpointslice_controller.go:283] "Starting endpoint slice controller"1333machine # [ 34.639257] k3s[815]: I0827 17:07:58.319690 815 shared_informer.go:370] "Waiting for caches to sync"1334machine # [ 34.640634] k3s[815]: I0827 17:07:58.319947 815 horizontal.go:204] "Starting HPA controller"1335machine # [ 34.641846] k3s[815]: I0827 17:07:58.319958 815 shared_informer.go:370] "Waiting for caches to sync"1336machine # [ 34.643162] k3s[815]: I0827 17:07:58.320010 815 attach_detach_controller.go:335] "Starting attach detach controller"1337machine # [ 34.644683] k3s[815]: I0827 17:07:58.320057 815 shared_informer.go:370] "Waiting for caches to sync"1338machine # [ 34.646014] k3s[815]: I0827 17:07:58.320137 815 controller.go:423] "Starting resource claim controller"1339machine # [ 34.647244] k3s[815]: I0827 17:07:58.320149 815 shared_informer.go:370] "Waiting for caches to sync"1340machine # [ 34.648489] k3s[815]: I0827 17:07:58.320210 815 job_controller.go:254] "Starting job controller"1341machine # [ 34.649652] k3s[815]: I0827 17:07:58.320220 815 shared_informer.go:370] "Waiting for caches to sync"1342machine # [ 34.651122] k3s[815]: I0827 17:07:58.320269 815 deployment_controller.go:172] "Starting controller" controller="deployment"1343machine # [ 34.652974] k3s[815]: I0827 17:07:58.320281 815 shared_informer.go:370] "Waiting for caches to sync"1344machine # [ 34.654432] k3s[815]: I0827 17:07:58.320362 815 node_ipam_controller.go:142] "Starting ipam controller"1345machine # [ 34.655930] k3s[815]: I0827 17:07:58.320376 815 shared_informer.go:370] "Waiting for caches to sync"1346machine # [ 34.657444] k3s[815]: I0827 17:07:58.320423 815 stateful_set.go:180] "Starting stateful set controller"1347machine # [ 34.658902] k3s[815]: I0827 17:07:58.320434 815 shared_informer.go:370] "Waiting for caches to sync"1348machine # [ 34.660370] k3s[815]: I0827 17:07:58.320461 815 cleaner.go:83] "Starting CSR cleaner controller"1349machine # [ 34.661722] k3s[815]: I0827 17:07:58.320504 815 pvc_protection_controller.go:166] "Starting PVC protection controller"1350machine # [ 34.663262] k3s[815]: I0827 17:07:58.320516 815 shared_informer.go:370] "Waiting for caches to sync"1351machine # [ 34.664617] k3s[815]: I0827 17:07:58.320535 815 ttlafterfinished_controller.go:112] "Starting TTL after finished controller"1352machine # [ 34.666124] k3s[815]: I0827 17:07:58.320547 815 shared_informer.go:370] "Waiting for caches to sync"1353machine # [ 34.667345] k3s[815]: I0827 17:07:58.320579 815 shared_informer.go:370] "Waiting for caches to sync"1354machine # [ 34.668672] k3s[815]: I0827 17:07:58.320632 815 replica_set.go:241] "Starting controller" name="replicaset"1355machine # [ 34.669956] k3s[815]: I0827 17:07:58.320642 815 shared_informer.go:370] "Waiting for caches to sync"1356machine # [ 34.671227] k3s[815]: I0827 17:07:58.321339 815 garbagecollector.go:141] "Starting controller" controller="garbagecollector"1357machine # [ 34.672798] k3s[815]: I0827 17:07:58.321365 815 shared_informer.go:370] "Waiting for caches to sync"1358machine # [ 34.674012] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Event occurred" apiVersion= fieldPath= kind=Node logger=k3s message="Deferred node password secret validation complete" object=machine reason=NodePasswordValidationComplete type=Normal1359machine # [ 34.676819] k3s[815]: I0827 17:07:58.321433 815 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-serving"1360machine # [ 34.678511] k3s[815]: I0827 17:07:58.321443 815 shared_informer.go:370] "Waiting for caches to sync"1361machine # [ 34.679878] k3s[815]: I0827 17:07:58.321461 815 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-client"1362machine # [ 34.681901] k3s[815]: I0827 17:07:58.321505 815 shared_informer.go:370] "Waiting for caches to sync"1363machine # [ 34.683281] k3s[815]: I0827 17:07:58.321522 815 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kube-apiserver-client"1364machine # [ 34.685254] k3s[815]: I0827 17:07:58.321531 815 shared_informer.go:370] "Waiting for caches to sync"1365machine # [ 34.686533] k3s[815]: I0827 17:07:58.321557 815 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"1366machine # [ 34.689271] k3s[815]: I0827 17:07:58.321739 815 resource_quota_controller.go:297] "Starting resource quota controller"1367machine # [ 34.690740] k3s[815]: I0827 17:07:58.321752 815 shared_informer.go:370] "Waiting for caches to sync"1368machine # [ 34.692005] k3s[815]: I0827 17:07:58.322008 815 graph_builder.go:386] "Running" component="GraphBuilder"1369machine # [ 34.693331] k3s[815]: I0827 17:07:58.322051 815 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"1370machine # [ 34.696281] k3s[815]: I0827 17:07:58.322139 815 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"1371machine # [ 34.698983] k3s[815]: I0827 17:07:58.322204 815 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"1372machine # [ 34.701775] k3s[815]: I0827 17:07:58.322526 815 resource_quota_monitor.go:309] "QuotaMonitor running"1373machine # [ 34.703082] k3s[815]: I0827 17:07:58.341857 815 shared_informer.go:370] "Waiting for caches to sync"1374machine # [ 34.704386] k3s[815]: I0827 17:07:58.425856 815 shared_informer.go:370] "Waiting for caches to sync"1375machine # [ 34.930777] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/klipper-helm:v0.13.3-build20260727"1376machine # [ 34.960145] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/klipper-helm@sha256:5425a2b4613d2458dbdff99218e8d487ebb59c20e7a941f061c0777070f0aac1"1377machine # [ 34.962482] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/klipper-lb:v0.4.17"1378machine # [ 34.969793] k3s[815]: I0827 17:07:58.727146 815 shared_informer.go:377] "Caches are synced"1379machine # [ 34.974401] k3s[815]: I0827 17:07:58.731432 815 shared_informer.go:377] "Caches are synced"1380machine # [ 34.980234] k3s[815]: I0827 17:07:58.731559 815 shared_informer.go:377] "Caches are synced"1381machine # [ 34.981562] k3s[815]: I0827 17:07:58.731627 815 shared_informer.go:377] "Caches are synced"1382machine # [ 34.982830] k3s[815]: I0827 17:07:58.731678 815 shared_informer.go:377] "Caches are synced"1383machine # [ 34.984064] k3s[815]: I0827 17:07:58.731779 815 shared_informer.go:377] "Caches are synced"1384machine # [ 34.985344] k3s[815]: I0827 17:07:58.731845 815 shared_informer.go:377] "Caches are synced"1385machine # [ 34.986549] k3s[815]: I0827 17:07:58.731874 815 shared_informer.go:377] "Caches are synced"1386machine # [ 34.987773] k3s[815]: I0827 17:07:58.731917 815 shared_informer.go:377] "Caches are synced"1387machine # [ 34.989113] k3s[815]: I0827 17:07:58.731941 815 shared_informer.go:377] "Caches are synced"1388machine # [ 34.990321] k3s[815]: I0827 17:07:58.731960 815 shared_informer.go:377] "Caches are synced"1389machine # [ 34.991558] k3s[815]: time="2026-08-27T17:07:58Z" 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=Normal1390machine # [ 35.004824] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/klipper-lb@sha256:910944bb0bd94f060a82a56ca1ea1c577d3e49b3473a093a47a985f32e92d94a"1391machine # [ 35.008217] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.36"1392machine # [ 35.010623] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/local-path-provisioner@sha256:1eba82e9c386038b4af6d69cca7519fac738c28c42735ed48ce70c882ad0d80f"1393machine # [ 35.014999] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/mirrored-coredns-coredns:1.14.6"1394machine # [ 35.017075] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/mirrored-coredns-coredns@sha256:900f9c109f7a33545d3c811516e8376df9019147b750f5ce3e254468769176ea"1395machine # [ 35.024095] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/mirrored-library-busybox:1.37.0"1396machine # [ 35.026193] k3s[815]: time="2026-08-27T17:07:58Z" 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=Normal1397machine # [ 35.030579] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/mirrored-library-busybox@sha256:101b4afd76732482eff9b95cae5f94bcf295e521fbec4e01b69c5421f3f3f3e5"1398machine # [ 35.033891] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/mirrored-library-traefik:3.7.8"1399machine # [ 35.036862] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/mirrored-library-traefik@sha256:4299bbed850421258fc5448c2e0e6ad350981d4d335a68de11b92448aedbefe5"1400machine # [ 35.039621] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/mirrored-metrics-server:v0.9.0"1401machine # [ 35.041510] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/mirrored-metrics-server@sha256:d9862115e7c7881280d3d75ca26bda8ffc0fc213315979575bf23ce9826205c0"1402machine # [ 35.044381] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Imported docker.io/rancher/mirrored-pause:3.10.2"1403machine # [ 35.046463] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Unable to set control-plane role label: nodes \"machine\" not found"1404machine # [ 35.048378] k3s[815]: time="2026-08-27T17:07:58Z" level=info msg="Tagged docker.io/rancher/mirrored-pause@sha256:f548e0e8e3dc1896ca956272154dde3314e8cc4fde0a57577ee9fa1c63f5baf4"1405machine # [ 35.057791] k3s[815]: I0827 17:07:58.813766 815 shared_informer.go:377] "Caches are synced"1406machine # [ 35.061077] k3s[815]: I0827 17:07:58.818422 815 shared_informer.go:377] "Caches are synced"1407machine # [ 35.062930] k3s[815]: I0827 17:07:58.818928 815 shared_informer.go:377] "Caches are synced"1408machine # [ 35.085654] k3s[815]: I0827 17:07:58.818977 815 shared_informer.go:377] "Caches are synced"1409machine # [ 35.087165] k3s[815]: I0827 17:07:58.819026 815 shared_informer.go:377] "Caches are synced"1410machine # [ 35.088530] k3s[815]: I0827 17:07:58.819055 815 shared_informer.go:377] "Caches are synced"1411machine # [ 35.089851] k3s[815]: I0827 17:07:58.819083 815 shared_informer.go:377] "Caches are synced"1412machine # [ 35.091062] k3s[815]: I0827 17:07:58.819335 815 shared_informer.go:377] "Caches are synced"1413machine # [ 35.092604] k3s[815]: I0827 17:07:58.819366 815 shared_informer.go:377] "Caches are synced"1414machine # [ 35.093973] k3s[815]: I0827 17:07:58.819896 815 shared_informer.go:377] "Caches are synced"1415machine # [ 35.095314] k3s[815]: I0827 17:07:58.819980 815 shared_informer.go:377] "Caches are synced"1416machine # [ 35.097887] k3s[815]: I0827 17:07:58.820057 815 shared_informer.go:377] "Caches are synced"1417machine # [ 35.099504] k3s[815]: I0827 17:07:58.820085 815 shared_informer.go:377] "Caches are synced"1418machine # [ 35.101216] k3s[815]: I0827 17:07:58.820229 815 shared_informer.go:377] "Caches are synced"1419machine # [ 35.102584] k3s[815]: I0827 17:07:58.820268 815 shared_informer.go:377] "Caches are synced"1420machine # [ 35.103974] k3s[815]: I0827 17:07:58.820300 815 shared_informer.go:377] "Caches are synced"1421machine # [ 35.105540] k3s[815]: I0827 17:07:58.821122 815 shared_informer.go:377] "Caches are synced"1422machine # [ 35.106927] k3s[815]: I0827 17:07:58.821180 815 shared_informer.go:377] "Caches are synced"1423machine # [ 35.108080] k3s[815]: I0827 17:07:58.824582 815 shared_informer.go:377] "Caches are synced"1424machine # [ 35.109215] k3s[815]: I0827 17:07:58.824612 815 garbagecollector.go:166] "Garbage collector: all resource monitors have synced"1425machine # [ 35.111140] k3s[815]: I0827 17:07:58.824623 815 garbagecollector.go:169] "Proceeding to collect garbage"1426machine # [ 35.112701] k3s[815]: I0827 17:07:58.824737 815 shared_informer.go:377] "Caches are synced"1427machine # [ 35.114104] k3s[815]: I0827 17:07:58.825053 815 shared_informer.go:377] "Caches are synced"1428machine # [ 35.115528] k3s[815]: I0827 17:07:58.825145 815 shared_informer.go:377] "Caches are synced"1429machine # [ 35.118049] k3s[815]: I0827 17:07:58.826151 815 shared_informer.go:377] "Caches are synced"1430machine # [ 35.119636] k3s[815]: I0827 17:07:58.826487 815 shared_informer.go:377] "Caches are synced"1431machine # [ 35.121437] k3s[815]: I0827 17:07:58.826517 815 shared_informer.go:377] "Caches are synced"1432machine # [ 35.124280] k3s[815]: I0827 17:07:58.826540 815 shared_informer.go:377] "Caches are synced"1433machine # [ 35.125527] k3s[815]: I0827 17:07:58.826571 815 shared_informer.go:377] "Caches are synced"1434machine # [ 35.126749] k3s[815]: I0827 17:07:58.826812 815 shared_informer.go:377] "Caches are synced"1435machine # [ 35.127969] k3s[815]: I0827 17:07:58.827411 815 shared_informer.go:377] "Caches are synced"1436machine # [ 35.129308] k3s[815]: I0827 17:07:58.827485 815 shared_informer.go:377] "Caches are synced"1437machine # [ 35.130650] k3s[815]: I0827 17:07:58.827528 815 range_allocator.go:177] "Sending events to api server"1438machine # [ 35.133464] k3s[815]: I0827 17:07:58.827553 815 range_allocator.go:181] "Starting range CIDR allocator"1439machine # [ 35.135984] k3s[815]: I0827 17:07:58.827563 815 shared_informer.go:370] "Waiting for caches to sync"1440machine # [ 35.137783] k3s[815]: I0827 17:07:58.827570 815 shared_informer.go:377] "Caches are synced"1441machine # [ 35.139363] k3s[815]: I0827 17:07:58.827613 815 shared_informer.go:377] "Caches are synced"1442machine # [ 35.143227] k3s[815]: I0827 17:07:58.827642 815 shared_informer.go:377] "Caches are synced"1443machine # [ 35.145279] k3s[815]: I0827 17:07:58.842001 815 shared_informer.go:377] "Caches are synced"1444machine # [ 35.168677] k3s[815]: I0827 17:07:58.920934 815 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161445machine # [ 35.171818] k3s[815]: I0827 17:07:58.928481 815 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161446machine # [ 35.231873] k3s[815]: I0827 17:07:58.928814 815 controller.go:667] quota admission added evaluator for: helmcharts.helm.cattle.io1447machine # [ 35.237750] k3s[815]: time="2026-08-27T17:07:58Z" 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=Normal1448machine # [ 35.242414] k3s[815]: time="2026-08-27T17:07:58Z" 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=Normal1449machine # [ 35.292309] k3s[815]: time="2026-08-27T17:07:59Z" 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=Normal1450machine # [ 35.353739] k3s[815]: I0827 17:07:59.111112 815 controller.go:667] quota admission added evaluator for: jobs.batch1451machine # [ 35.384770] k3s[815]: I0827 17:07:59.142115 815 controller.go:667] quota admission added evaluator for: replicasets.apps1452machine # [ 35.492100] k3s[815]: time="2026-08-27T17:07:59Z" 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=Normal1453machine # [ 35.570995] k3s[815]: time="2026-08-27T17:07:59Z" 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=Normal1454machine # [ 35.723713] k3s[815]: time="2026-08-27T17:07:59Z" 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=Normal1455machine # Error from server (NotFound): namespaces "niks3" not found1456machine # [ 35.915657] k3s[815]: time="2026-08-27T17:07:59Z" 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=Normal1457machine # [ 35.938684] k3s[815]: time="2026-08-27T17:07:59Z" level=info msg="Imported 8 images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-arm64.tar.zst in 8.82804758s"1458machine # [ 35.942065] k3s[815]: time="2026-08-27T17:07:59Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/niks3-server.tar"1459machine # [ 36.010205] k3s[815]: time="2026-08-27T17:07:59Z" 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=Normal1460machine # [ 36.040262] k3s[815]: time="2026-08-27T17:07:59Z" level=info msg="Unable to set control-plane role label: nodes \"machine\" not found"1461machine # [ 36.158721] k3s[815]: time="2026-08-27T17:07:59Z" 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::55d6:1ccb:f2c5:cfd8 --node-labels= --read-only-port=0"1462machine # [ 36.164498] k3s[815]: 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.1463machine # [ 36.183850] k3s[815]: I0827 17:07:59.940329 815 server.go:521] "Kubelet version" kubeletVersion="v1.35.7+k3s1"1464machine # [ 36.187748] k3s[815]: I0827 17:07:59.940427 815 server.go:523] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1465machine # [ 36.190537] k3s[815]: I0827 17:07:59.940482 815 watchdog_linux.go:95] "Systemd watchdog is not enabled"1466machine # [ 36.193223] k3s[815]: I0827 17:07:59.940494 815 watchdog_linux.go:138] "Systemd watchdog is not enabled or the interval is invalid, so health checking will not be started."1467machine # [ 36.196957] k3s[815]: I0827 17:07:59.945825 815 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt"1468machine # [ 36.199116] k3s[815]: I0827 17:07:59.956114 815 server.go:1414] "Using cgroup driver setting received from the CRI runtime" cgroupDriver="systemd"1469machine # [ 36.212706] k3s[815]: I0827 17:07:59.969926 815 server.go:771] "--cgroups-per-qos enabled, but --cgroup-root was not specified. Defaulting to /"1470machine # [ 36.216203] k3s[815]: I0827 17:07:59.970342 815 server.go:832] "NoSwap is set due to memorySwapBehavior not specified" memorySwapBehavior="" FailSwapOn=false1471machine # [ 36.218424] k3s[815]: I0827 17:07:59.975105 815 container_manager_linux.go:272] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]1472machine # [ 36.220712] k3s[815]: I0827 17:07:59.975230 815 container_manager_linux.go:277] "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":"imagefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"Signal":"nodefs.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,"PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null,"CgroupVersion":2}1473machine # [ 36.236252] k3s[815]: I0827 17:07:59.975838 815 topology_manager.go:143] "Creating topology manager with none policy"1474machine # [ 36.238749] k3s[815]: I0827 17:07:59.975864 815 container_manager_linux.go:308] "Creating device plugin manager"1475machine # [ 36.240979] k3s[815]: I0827 17:07:59.976120 815 container_manager_linux.go:317] "Creating Dynamic Resource Allocation (DRA) manager"1476machine # [ 36.245310] k3s[815]: I0827 17:07:59.981156 815 state_mem.go:41] "Initialized" logger="CPUManager state memory"1477machine # [ 36.247210] k3s[815]: I0827 17:07:59.982568 815 kubelet.go:482] "Attempting to sync node with API server"1478machine # [ 36.250908] k3s[815]: I0827 17:07:59.982809 815 kubelet.go:383] "Adding static pod path" path="/var/lib/rancher/k3s/agent/pod-manifests"1479machine # [ 36.252859] k3s[815]: I0827 17:07:59.989147 815 kubelet.go:394] "Adding apiserver pod source"1480machine # [ 36.254347] k3s[815]: I0827 17:07:59.991412 815 apiserver.go:42] "Waiting for node sync before watching apiserver pods"1481machine # [ 36.256045] k3s[815]: I0827 17:07:59.996900 815 kuberuntime_manager.go:304] "Container runtime initialized" containerRuntime="containerd" version="2.2.5-k3s2" apiVersion="v1"1482machine # [ 36.258328] k3s[815]: I0827 17:08:00.000775 815 kubelet.go:945] "Not starting ClusterTrustBundle informer because we are in static kubelet mode or the ClusterTrustBundleProjection featuregate is disabled"1483machine # [ 36.261020] k3s[815]: I0827 17:08:00.000859 815 kubelet.go:972] "Not starting PodCertificateRequest manager because we are in static kubelet mode or the PodCertificateProjection feature gate is disabled"1484machine # [ 36.263457] k3s[815]: I0827 17:08:00.009452 815 server.go:1252] "Started kubelet"1485machine # [ 36.264895] k3s[815]: I0827 17:08:00.017791 815 server.go:182] "Starting to listen" address="0.0.0.0" port=102501486machine # [ 36.269497] k3s[815]: I0827 17:08:00.019133 815 ratelimit.go:56] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=101487machine # [ 36.271565] k3s[815]: I0827 17:08:00.019312 815 server_v1.go:49] "podresources" method="list" useActivePods=true1488machine # [ 36.274812] k3s[815]: I0827 17:08:00.019768 815 server.go:254] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock"1489machine # [ 36.283504] k3s[815]: I0827 17:08:00.027299 815 server.go:317] "Adding debug handlers to kubelet server"1490machine # [ 36.287336] k3s[815]: I0827 17:08:00.029921 815 fs_resource_analyzer.go:69] "Starting FS ResourceAnalyzer"1491machine # [ 36.289573] k3s[815]: I0827 17:08:00.031536 815 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"1492machine # [ 36.292570] k3s[815]: I0827 17:08:00.034545 815 volume_manager.go:311] "Starting Kubelet Volume Manager"1493machine # [ 36.295183] k3s[815]: E0827 17:08:00.034948 815 kubelet_node_status.go:392] "Error getting the current node from lister" err="node \"machine\" not found"1494machine # [ 36.297573] k3s[815]: I0827 17:08:00.036758 815 desired_state_of_world_populator.go:146] "Desired state populator starts to run"1495machine # [ 36.299844] k3s[815]: I0827 17:08:00.037107 815 reconciler.go:29] "Reconciler: start to sync state"1496machine # [ 36.301783] k3s[815]: I0827 17:08:00.049938 815 factory.go:223] Registration of the systemd container factory successfully1497machine # [ 36.307225] k3s[815]: I0827 17:08:00.050192 815 factory.go:221] 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 directory1498machine # [ 36.313919] k3s[815]: E0827 17:08:00.056338 815 kubelet.go:1661] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"1499machine # [ 36.324103] k3s[815]: I0827 17:08:00.068173 815 factory.go:223] Registration of the containerd container factory successfully1500machine # [ 36.345643] k3s[815]: E0827 17:08:00.102918 815 nodelease.go:50] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"machine\" not found" node="machine"1501machine # [ 36.354859] k3s[815]: I0827 17:08:00.112100 815 cpu_manager.go:225] "Starting" policy="none"1502machine # [ 36.358855] k3s[815]: I0827 17:08:00.114393 815 cpu_manager.go:226] "Reconciling" reconcilePeriod="10s"1503machine # [ 36.393561] k3s[815]: I0827 17:08:00.114459 815 state_mem.go:41] "Initialized" logger="CPUManager state checkpoint.CPUManager state memory"1504machine # [ 36.396712] k3s[815]: I0827 17:08:00.119238 815 policy_none.go:50] "Start"1505machine # [ 36.397877] k3s[815]: I0827 17:08:00.119331 815 memory_manager.go:187] "Starting memorymanager" policy="None"1506machine # [ 36.399540] k3s[815]: I0827 17:08:00.119445 815 state_mem.go:36] "Initializing new in-memory state store" logger="Memory Manager state checkpoint"1507machine # [ 36.401773] k3s[815]: I0827 17:08:00.127219 815 policy_none.go:44] "Start"1508machine # [ 36.403082] k3s[815]: E0827 17:08:00.135810 815 kubelet_node_status.go:392] "Error getting the current node from lister" err="node \"machine\" not found"1509machine # [ 36.406142] systemd[1]: Created slice libcontainer container kubepods.slice.1510machine # [ 36.431534] systemd[1]: Created slice libcontainer container kubepods-burstable.slice.1511machine # [ 36.453010] systemd[1]: Created slice libcontainer container kubepods-besteffort.slice.1512machine # [ 36.490287] k3s[815]: E0827 17:08:00.247594 815 kubelet_node_status.go:392] "Error getting the current node from lister" err="node \"machine\" not found"1513machine # [ 36.509793] k3s[815]: E0827 17:08:00.249214 815 manager.go:525] "Failed to read data from checkpoint" err="checkpoint is not found" checkpoint="kubelet_internal_checkpoint"1514machine # [ 36.516388] k3s[815]: I0827 17:08:00.250811 815 eviction_manager.go:194] "Eviction manager: starting control loop"1515machine # [ 36.524452] k3s[815]: I0827 17:08:00.250853 815 container_log_manager.go:146] "Initializing container log rotate workers" workers=1 monitorPeriod="10s"1516machine # [ 36.527338] k3s[815]: I0827 17:08:00.253199 815 plugin_manager.go:121] "Starting Kubelet Plugin Manager"1517machine # [ 36.530373] k3s[815]: E0827 17:08:00.268997 815 eviction_manager.go:272] "eviction manager: failed to check if we have separate container filesystem. Ignoring." err="no imagefs label for configured runtime"1518machine # [ 36.538876] k3s[815]: E0827 17:08:00.269109 815 eviction_manager.go:297] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"machine\" not found"1519machine # [ 36.613443] k3s[815]: I0827 17:08:00.370350 815 kubelet_node_status.go:74] "Attempting to register node" node="machine"1520machine # [ 36.648179] k3s[815]: I0827 17:08:00.403051 815 kubelet_node_status.go:77] "Successfully registered node" node="machine"1521machine # [ 36.650293] k3s[815]: E0827 17:08:00.403139 815 kubelet_node_status.go:474] "Error updating node status, will retry" err="error getting node \"machine\": node \"machine\" not found"1522machine # [ 36.655387] k3s[815]: I0827 17:08:00.412717 815 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"1523machine # [ 36.661488] k3s[815]: I0827 17:08:00.418813 815 node_controller.go:429] Initializing node machine with cloud provider1524machine # [ 36.673851] k3s[815]: I0827 17:08:00.431030 815 node_controller.go:233] error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing1525machine # [ 36.678855] k3s[815]: E0827 17:08:00.434268 815 node_controller.go:244] "Unhandled Error" err="error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing" logger="UnhandledError"1526machine # [ 36.687030] k3s[815]: time="2026-08-27T17:08:00Z" level=info msg="Adding node OwnerReference to node-password secret machine.node-password.k3s"1527machine # [ 36.691248] k3s[815]: I0827 17:08:00.442853 815 node_controller.go:429] Initializing node machine with cloud provider1528machine # [ 36.696597] k3s[815]: I0827 17:08:00.443977 815 node_controller.go:233] error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing1529machine # [ 36.701391] k3s[815]: E0827 17:08:00.444085 815 node_controller.go:244] "Unhandled Error" err="error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing" logger="UnhandledError"1530machine # [ 36.757758] k3s[815]: I0827 17:08:00.456022 815 node_controller.go:429] Initializing node machine with cloud provider1531machine # [ 36.759556] k3s[815]: I0827 17:08:00.456154 815 node_controller.go:233] error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing1532machine # [ 36.763060] k3s[815]: E0827 17:08:00.456201 815 node_controller.go:244] "Unhandled Error" err="error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing" logger="UnhandledError"1533machine # [ 36.766699] k3s[815]: I0827 17:08:00.469051 815 range_allocator.go:433] "Set node PodCIDR" node="machine" podCIDRs=["10.42.0.0/24"]1534machine # [ 36.769880] k3s[815]: I0827 17:08:00.470027 815 node_controller.go:429] Initializing node machine with cloud provider1535machine # [ 36.775465] k3s[815]: I0827 17:08:00.470106 815 node_controller.go:233] error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing1536machine # [ 36.783123] k3s[815]: E0827 17:08:00.470356 815 node_controller.go:244] "Unhandled Error" err="error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing" logger="UnhandledError"1537machine # [ 36.787562] k3s[815]: I0827 17:08:00.478273 815 node_controller.go:429] Initializing node machine with cloud provider1538machine # [ 36.792229] k3s[815]: I0827 17:08:00.478355 815 node_controller.go:233] error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing1539machine # [ 36.794823] k3s[815]: E0827 17:08:00.478415 815 node_controller.go:244] "Unhandled Error" err="error syncing 'machine': failed to get instance metadata for node machine: address annotations not yet set, requeuing" logger="UnhandledError"1540machine # [ 36.798145] k3s[815]: time="2026-08-27T17:08:00Z" level=info msg="Synced coredns NodeHosts entries for machine"1541machine # [ 36.799798] k3s[815]: I0827 17:08:00.533627 815 node_controller.go:429] Initializing node machine with cloud provider1542machine # [ 36.804478] k3s[815]: time="2026-08-27T17:08:00Z" level=info msg="Annotations and labels have been set successfully on node: machine"1543machine # [ 36.806519] k3s[815]: time="2026-08-27T17:08:00Z" level=info msg="Starting flannel with backend vxlan"1544machine # [ 36.817934] k3s[815]: I0827 17:08:00.575237 815 kubelet_network_linux.go:54] "Initialized iptables rules." protocol="IPv4"1545machine # [ 36.830817] k3s[815]: I0827 17:08:00.587923 815 kuberuntime_manager.go:2095] "Updating runtime config through cri with podcidr" CIDR="10.42.0.0/24"1546machine # [ 36.845061] k3s[815]: I0827 17:08:00.602319 815 kubelet_network_linux.go:54] "Initialized iptables rules." protocol="IPv6"1547machine # [ 36.852522] k3s[815]: I0827 17:08:00.602412 815 status_manager.go:249] "Starting to sync pod status with apiserver"1548machine # [ 36.854297] k3s[815]: I0827 17:08:00.602528 815 kubelet.go:2506] "Starting kubelet main sync loop"1549machine # [ 36.855684] k3s[815]: E0827 17:08:00.602687 815 kubelet.go:2530] "Skipping pod synchronization" err="PLEG is not healthy: pleg has yet to be successful"1550machine # [ 36.902683] k3s[815]: I0827 17:08:00.660018 815 kubelet_network.go:47] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="10.42.0.0/24"1551machine # [ 36.973913] k3s[815]: I0827 17:08:00.731232 815 kubelet_node_status.go:427] "Fast updating node status as it just became ready"1552machine # [ 37.010753] k3s[815]: I0827 17:08:00.767447 815 node_controller.go:474] Successfully initialized node machine with cloud provider1553machine # [ 37.012793] k3s[815]: I0827 17:08:00.769101 815 event.go:389] "Event occurred" object="machine" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="Synced" message="Node synced successfully"1554machine # [ 37.046298] k3s[815]: I0827 17:08:00.803605 815 server.go:173] "Starting Kubernetes Scheduler" version="v1.35.7+k3s1"1555machine # [ 37.048564] k3s[815]: I0827 17:08:00.805926 815 server.go:175] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1556machine # [ 37.160417] k3s[815]: I0827 17:08:00.844015 815 secure_serving.go:211] Serving securely on 127.0.0.1:102591557machine # [ 37.162145] k3s[815]: I0827 17:08:00.845566 815 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1558machine # [ 37.163814] k3s[815]: I0827 17:08:00.845635 815 shared_informer.go:370] "Waiting for caches to sync"1559machine # [ 37.165656] k3s[815]: I0827 17:08:00.845703 815 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"1560machine # [ 37.169289] k3s[815]: I0827 17:08:00.845786 815 tlsconfig.go:243] "Starting DynamicServingCertificateController"1561machine # [ 37.171096] k3s[815]: I0827 17:08:00.853606 815 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1562machine # [ 37.173827] k3s[815]: I0827 17:08:00.853711 815 shared_informer.go:370] "Waiting for caches to sync"1563machine # [ 37.175534] k3s[815]: I0827 17:08:00.853811 815 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1564machine # [ 37.182623] k3s[815]: I0827 17:08:00.853855 815 shared_informer.go:370] "Waiting for caches to sync"1565machine # [ 37.187731] k3s[815]: time="2026-08-27T17:08:00Z" level=info msg="Labels and annotations have been set successfully on node: machine"1566machine # [ 37.190603] k3s[815]: time="2026-08-27T17:08:00Z" level=info msg="Flannel found PodCIDR assigned for node machine"1567machine # [ 37.192702] k3s[815]: time="2026-08-27T17:08:00Z" level=info msg="The interface eth0 with ipv4 address 10.0.2.15 will be used by flannel"1568machine # [ 37.203737] k3s[815]: I0827 17:08:00.961061 815 kube.go:139] Waiting 10m0s for node controller to sync1569machine # [ 37.236395] k3s[815]: I0827 17:08:00.965500 815 kube.go:537] Starting kube subnet manager1570machine # [ 37.238283] k3s[815]: I0827 17:08:00.995657 815 apiserver.go:52] "Watching apiserver"1571machine # [ 37.306727] k3s[815]: I0827 17:08:01.063937 815 server.go:218] "Successfully retrieved NodeIPs" NodeIPs=["10.0.2.15","fec0::55d6:1ccb:f2c5:cfd8"]1572machine # [ 37.309422] k3s[815]: E0827 17:08:01.064355 815 server.go:255] "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`"1573machine # Error from server (NotFound): namespaces "niks3" not found1574machine # [ 37.380463] k3s[815]: I0827 17:08:01.137761 815 server.go:264] "kube-proxy running in dual-stack mode" primary ipFamily="IPv4"1575machine # [ 37.382641] k3s[815]: I0827 17:08:01.137877 815 server_linux.go:136] "Using iptables Proxier"1576machine # [ 37.439526] k3s[815]: I0827 17:08:01.196841 815 proxier.go:242] "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"1577machine # [ 37.468417] k3s[815]: I0827 17:08:01.225614 815 server.go:529] "Version info" version="v1.35.7+k3s1"1578machine # [ 37.469821] k3s[815]: I0827 17:08:01.225708 815 server.go:531] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1579machine # [ 37.473703] k3s[815]: I0827 17:08:01.227502 815 config.go:106] "Starting endpoint slice config controller"1580machine # [ 37.476181] k3s[815]: I0827 17:08:01.227548 815 shared_informer.go:349] "Waiting for caches to sync" controller="endpoint slice config"1581machine # [ 37.488420] k3s[815]: I0827 17:08:01.228021 815 config.go:200] "Starting service config controller"1582machine # [ 37.490002] k3s[815]: I0827 17:08:01.228044 815 shared_informer.go:349] "Waiting for caches to sync" controller="service config"1583machine # [ 37.491733] k3s[815]: I0827 17:08:01.228739 815 config.go:403] "Starting serviceCIDR config controller"1584machine # [ 37.496273] k3s[815]: I0827 17:08:01.228858 815 shared_informer.go:349] "Waiting for caches to sync" controller="serviceCIDR config"1585machine # [ 37.498217] k3s[815]: I0827 17:08:01.228927 815 config.go:309] "Starting node config controller"1586machine # [ 37.499679] k3s[815]: I0827 17:08:01.228985 815 shared_informer.go:349] "Waiting for caches to sync" controller="node config"1587machine # [ 37.516337] k3s[815]: I0827 17:08:01.229022 815 shared_informer.go:356] "Caches are synced" controller="node config"1588machine # [ 37.571643] k3s[815]: I0827 17:08:01.328784 815 shared_informer.go:356] "Caches are synced" controller="service config"1589machine # [ 37.573836] k3s[815]: I0827 17:08:01.330030 815 shared_informer.go:356] "Caches are synced" controller="serviceCIDR config"1590machine # [ 37.579677] k3s[815]: I0827 17:08:01.337014 815 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world"1591machine # [ 37.588430] k3s[815]: I0827 17:08:01.345738 815 shared_informer.go:377] "Caches are synced"1592machine # [ 37.597320] k3s[815]: I0827 17:08:01.354635 815 shared_informer.go:377] "Caches are synced"1593machine # [ 37.608227] k3s[815]: I0827 17:08:01.359799 815 shared_informer.go:377] "Caches are synced"1594machine # [ 37.662272] systemd[1]: Created slice libcontainer container kubepods-burstable-pod69cfa016_664f_4d3b_bcfc_0fdeee31547f.slice.1595machine # [ 37.670519] k3s[815]: I0827 17:08:01.427848 815 shared_informer.go:356] "Caches are synced" controller="endpoint slice config"1596machine # [ 37.703669] k3s[815]: I0827 17:08:01.460140 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"config-volume\" (UniqueName: \"kubernetes.io/configmap/69cfa016-664f-4d3b-bcfc-0fdeee31547f-config-volume\") pod \"coredns-c5fdd76cf-fcmv5\" (UID: \"69cfa016-664f-4d3b-bcfc-0fdeee31547f\") " pod="kube-system/coredns-c5fdd76cf-fcmv5"1597machine # [ 37.714346] k3s[815]: I0827 17:08:01.460226 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"custom-config-volume\" (UniqueName: \"kubernetes.io/configmap/69cfa016-664f-4d3b-bcfc-0fdeee31547f-custom-config-volume\") pod \"coredns-c5fdd76cf-fcmv5\" (UID: \"69cfa016-664f-4d3b-bcfc-0fdeee31547f\") " pod="kube-system/coredns-c5fdd76cf-fcmv5"1598machine # [ 37.726791] k3s[815]: I0827 17:08:01.460275 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-helm\") pod \"helm-install-niks3-nwfx8\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") " pod="kube-system/helm-install-niks3-nwfx8"1599machine # [ 37.732681] k3s[815]: I0827 17:08:01.460301 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-cache\") pod \"helm-install-niks3-nwfx8\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") " pod="kube-system/helm-install-niks3-nwfx8"1600machine # [ 37.741515] k3s[815]: I0827 17:08:01.460342 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-config\") pod \"helm-install-niks3-nwfx8\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") " pod="kube-system/helm-install-niks3-nwfx8"1601machine # [ 37.748196] k3s[815]: I0827 17:08:01.460400 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"content\" (UniqueName: \"kubernetes.io/configmap/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-content\") pod \"helm-install-niks3-nwfx8\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") " pod="kube-system/helm-install-niks3-nwfx8"1602machine # [ 37.754137] k3s[815]: I0827 17:08:01.460443 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-nc6jc\" (UniqueName: \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-kube-api-access-nc6jc\") pod \"helm-install-niks3-nwfx8\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") " pod="kube-system/helm-install-niks3-nwfx8"1603machine # [ 37.760089] k3s[815]: I0827 17:08:01.460511 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-mf54n\" (UniqueName: \"kubernetes.io/projected/69cfa016-664f-4d3b-bcfc-0fdeee31547f-kube-api-access-mf54n\") pod \"coredns-c5fdd76cf-fcmv5\" (UID: \"69cfa016-664f-4d3b-bcfc-0fdeee31547f\") " pod="kube-system/coredns-c5fdd76cf-fcmv5"1604machine # [ 37.768912] k3s[815]: I0827 17:08:01.460541 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-tmp\") pod \"helm-install-niks3-nwfx8\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") " pod="kube-system/helm-install-niks3-nwfx8"1605machine # [ 37.775939] k3s[815]: I0827 17:08:01.460601 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"values\" (UniqueName: \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-values\") pod \"helm-install-niks3-nwfx8\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") " pod="kube-system/helm-install-niks3-nwfx8"1606machine # [ 37.781922] systemd[1]: Created slice libcontainer container kubepods-burstable-pod64a48f06_1cc7_4e9f_99a5_2d6d346e416b.slice.1607machine # [ 37.938719] k3s[815]: time="2026-08-27T17:08:01Z" level=info msg="Tunnel authorizer set Kubelet Port 0.0.0.0:10250"1608machine # [ 38.035433] k3s[815]: time="2026-08-27T17:08:01Z" level=info msg="Imported docker.io/library/niks3-server:1.4.0-aarch64-linux"1609machine # [ 38.041520] k3s[815]: time="2026-08-27T17:08:01Z" level=info msg="Tagged docker.io/library/niks3-server@sha256:e8bd4070355215671e65b5d2fa84416cd74c14b42fb086c535123995524c1da7"1610machine # [ 38.091433] k3s[815]: time="2026-08-27T17:08:01Z" level=info msg="Imported 1 images from /var/lib/rancher/k3s/agent/images/niks3-server.tar in 2.1498575s"1611machine # [ 38.206633] k3s[815]: I0827 17:08:01.962671 815 kube.go:163] Node controller sync successful1612machine # [ 38.213807] k3s[815]: I0827 17:08:01.963284 815 vxlan.go:128] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false1613machine # [ 38.220611] k3s[815]: I0827 17:08:01.977902 815 kube.go:704] List of node(machine) annotations: map[string]string{"alpha.kubernetes.io/provided-node-ip":"10.0.2.15,fec0::55d6:1ccb:f2c5:cfd8", "k3s.io/hostname":"machine", "k3s.io/internal-ip":"10.0.2.15,fec0::55d6:1ccb:f2c5:cfd8", "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"}1614machine # [ 38.270441] (udev-worker)[1018]: Network interface NamePolicy= disabled on kernel command line.1615machine # [ 38.331111] k3s[815]: I0827 17:08:02.087124 815 kube.go:558] Creating the node lease for IPv4. This is the n.Spec.PodCIDRs: [10.42.0.0/24]1616machine # [ 38.334045] k3s[815]: I0827 17:08:02.091418 815 iptables.go:50] Starting flannel in iptables mode...1617machine # [ 38.336340] k3s[815]: time="2026-08-27T17:08:02Z" level=warning msg="no subnet found for key: FLANNEL_NETWORK in file: /run/flannel/subnet.env"1618machine # [ 38.349185] k3s[815]: time="2026-08-27T17:08:02Z" level=warning msg="no subnet found for key: FLANNEL_SUBNET in file: /run/flannel/subnet.env"1619machine # [ 38.355640] k3s[815]: time="2026-08-27T17:08:02Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_NETWORK in file: /run/flannel/subnet.env"1620machine # [ 38.359620] k3s[815]: time="2026-08-27T17:08:02Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_SUBNET in file: /run/flannel/subnet.env"1621machine # [ 38.364799] k3s[815]: I0827 17:08:02.091658 815 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 rules1622machine # [ 38.373189] k3s[815]: E0827 17:08:02.092396 815 log.go:32] "RunPodSandbox from runtime service failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"10555f78cbd9c63d54cc7602014531724140200d84f9a62588ff6281a523f7a9\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory"1623machine # [ 38.382135] k3s[815]: E0827 17:08:02.092526 815 kuberuntime_sandbox.go:71] "Failed to create sandbox for pod" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"10555f78cbd9c63d54cc7602014531724140200d84f9a62588ff6281a523f7a9\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/coredns-c5fdd76cf-fcmv5"1624machine # [ 38.388187] k3s[815]: E0827 17:08:02.092609 815 kuberuntime_manager.go:1568] "CreatePodSandbox for pod failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"10555f78cbd9c63d54cc7602014531724140200d84f9a62588ff6281a523f7a9\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/coredns-c5fdd76cf-fcmv5"1625machine # [ 38.402290] k3s[815]: E0827 17:08:02.092709 815 pod_workers.go:1324] "Error syncing pod, skipping" err="failed to \"CreatePodSandbox\" for \"coredns-c5fdd76cf-fcmv5_kube-system(69cfa016-664f-4d3b-bcfc-0fdeee31547f)\" with CreatePodSandboxError: \"Failed to create sandbox for pod \\\"coredns-c5fdd76cf-fcmv5_kube-system(69cfa016-664f-4d3b-bcfc-0fdeee31547f)\\\": rpc error: code = Unknown desc = failed to setup network for sandbox \\\"10555f78cbd9c63d54cc7602014531724140200d84f9a62588ff6281a523f7a9\\\": plugin type=\\\"flannel\\\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory\"" pod="kube-system/coredns-c5fdd76cf-fcmv5" podUID="69cfa016-664f-4d3b-bcfc-0fdeee31547f"1626machine # [ 38.415706] k3s[815]: E0827 17:08:02.110523 815 log.go:32] "RunPodSandbox from runtime service failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"8626fc9715b8ee7a78024cfcdf5f36e818b23fbefb73714a02e2514678d0e804\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory"1627machine # [ 38.429825] k3s[815]: E0827 17:08:02.111063 815 kuberuntime_sandbox.go:71] "Failed to create sandbox for pod" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"8626fc9715b8ee7a78024cfcdf5f36e818b23fbefb73714a02e2514678d0e804\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/helm-install-niks3-nwfx8"1628machine # [ 38.443044] k3s[815]: E0827 17:08:02.111137 815 kuberuntime_manager.go:1568] "CreatePodSandbox for pod failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"8626fc9715b8ee7a78024cfcdf5f36e818b23fbefb73714a02e2514678d0e804\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/helm-install-niks3-nwfx8"1629machine # [ 38.458115] k3s[815]: E0827 17:08:02.111283 815 pod_workers.go:1324] "Error syncing pod, skipping" err="failed to \"CreatePodSandbox\" for \"helm-install-niks3-nwfx8_kube-system(64a48f06-1cc7-4e9f-99a5-2d6d346e416b)\" with CreatePodSandboxError: \"Failed to create sandbox for pod \\\"helm-install-niks3-nwfx8_kube-system(64a48f06-1cc7-4e9f-99a5-2d6d346e416b)\\\": rpc error: code = Unknown desc = failed to setup network for sandbox \\\"8626fc9715b8ee7a78024cfcdf5f36e818b23fbefb73714a02e2514678d0e804\\\": plugin type=\\\"flannel\\\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory\"" pod="kube-system/helm-install-niks3-nwfx8" podUID="64a48f06-1cc7-4e9f-99a5-2d6d346e416b"1630machine # [ 38.526139] dhcpcd[601]: flannel.1: waiting for carrier1631machine # [ 38.530760] dhcpcd[601]: flannel.1: carrier acquired1632machine # [ 38.548401] dhcpcd[601]: flannel.1: IAID 2a:65:5e:731633machine # [ 38.550117] dhcpcd[601]: flannel.1: adding address fe80::a443:2aff:fe65:5e731634machine # [ 38.590175] k3s[815]: I0827 17:08:02.347399 815 iptables.go:111] Setting up masking rules1635machine # [ 38.641968] k3s[815]: I0827 17:08:02.399116 815 iptables.go:212] Changing default FORWARD chain policy to ACCEPT1636machine # [ 38.694231] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Wrote flannel subnet file to /run/flannel/subnet.env"1637machine # [ 38.697346] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Running flannel backend"1638machine # [ 38.698877] k3s[815]: I0827 17:08:02.451633 815 vxlan_network.go:68] watching for new subnet leases1639machine # [ 38.700635] k3s[815]: I0827 17:08:02.453360 815 vxlan_network.go:115] starting vxlan device watcher1640machine # [ 38.914261] k3s[815]: I0827 17:08:02.671603 815 iptables.go:358] bootstrap done1641machine # Error from server (NotFound): namespaces "niks3" not found1642machine # [ 38.968880] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Started tunnel to 10.0.2.15:6443"1643machine # [ 38.970827] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Stopped tunnel to 127.0.0.1:6443"1644machine # [ 38.972742] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Connecting to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1645machine # [ 38.975252] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"1646machine # [ 38.979552] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"1647machine # [ 38.982592] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Handling backend connection request [machine]"1648machine # [ 38.986215] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1649machine # [ 38.987964] k3s[815]: time="2026-08-27T17:08:02Z" level=info msg="Remotedialer connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1650machine # [ 39.008362] k3s[815]: I0827 17:08:02.765641 815 iptables.go:358] bootstrap done1651machine # [ 40.069676] k3s[815]: I0827 17:08:03.822322 815 node_lifecycle_controller.go:1234] "Initializing eviction metric for zone" zone=""1652machine # [ 40.076674] k3s[815]: I0827 17:08:03.822860 815 node_lifecycle_controller.go:886] "Missing timestamp for Node. Assuming now as a timestamp" node="machine"1653machine # [ 40.084280] k3s[815]: I0827 17:08:03.823191 815 node_lifecycle_controller.go:1080] "Controller detected that zone is now in new state" zone="" newState="Normal"1654machine # [ 40.236231] dhcpcd[601]: flannel.1: soliciting a DHCP lease1655machine # Error from server (NotFound): namespaces "niks3" not found1656machine # [ 40.819937] dhcpcd[601]: flannel.1: soliciting an IPv6 router1657machine # Error from server (NotFound): namespaces "niks3" not found1658machine # Error from server (NotFound): namespaces "niks3" not found1659machine # Error from server (NotFound): namespaces "niks3" not found1660machine # [ 45.235642] dhcpcd[601]: flannel.1: probing for an IPv4LL address1661machine # Error from server (NotFound): namespaces "niks3" not found1662machine # Error from server (NotFound): namespaces "niks3" not found1663machine # Error from server (NotFound): namespaces "niks3" not found1664machine # Error from server (NotFound): namespaces "niks3" not found1665machine # [ 50.722219] dhcpcd[601]: flannel.1: using IPv4LL address 169.254.197.731666machine # [ 50.726114] dhcpcd[601]: flannel.1: adding route to 169.254.0.0/161667machine # Error from server (NotFound): namespaces "niks3" not found1668machine # [ 51.948151] cni0: port 1(veth6f88f01c) entered blocking state1669machine # [ 51.948314] cni0: port 1(veth6f88f01c) entered disabled state1670machine # [ 51.948481] veth6f88f01c: entered allmulticast mode1671machine # [ 51.948766] veth6f88f01c: entered promiscuous mode1672machine # [ 51.983458] cni0: port 1(veth6f88f01c) entered blocking state1673machine # [ 51.983623] cni0: port 1(veth6f88f01c) entered forwarding state1674machine # [ 52.057436] (udev-worker)[1495]: Network interface NamePolicy= disabled on kernel command line.1675machine # [ 52.063832] (udev-worker)[1497]: Network interface NamePolicy= disabled on kernel command line.1676machine # [ 52.098373] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount1190281326.mount: Deactivated successfully.1677machine # [ 52.133742] dhcpcd[601]: veth6f88f01c: IAID 3d:90:ca:961678machine # [ 52.135505] dhcpcd[601]: veth6f88f01c: adding address fe80::1456:3dff:fe90:ca961679machine # [ 52.220754] systemd[1]: Started libcontainer container 74cd0a405ee3c626d14f336c2e6b88839e7c08f21ee04325d70c67c2ebb094b4.1680machine # [ 52.224807] dhcpcd[601]: veth6f88f01c: soliciting a DHCP lease1681machine # [ 52.880174] dhcpcd[601]: flannel.1: no IPv6 Routers available1682machine # Error from server (NotFound): namespaces "niks3" not found1683machine # [ 53.635741] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount2557948493.mount: Deactivated successfully.1684machine # [ 53.724770] systemd[1]: Started libcontainer container 4f5e958d6ea0d53a1ac461338223a1c40498d29d8d311535f06fd880d40534ca.1685machine # [ 53.894675] cni0: port 2(veth62a77d1d) entered blocking state1686machine # [ 53.894770] cni0: port 2(veth62a77d1d) entered disabled state1687machine # [ 53.894847] veth62a77d1d: entered allmulticast mode1688machine # [ 53.894998] veth62a77d1d: entered promiscuous mode1689machine # [ 53.929356] cni0: port 2(veth62a77d1d) entered blocking state1690machine # [ 53.929461] cni0: port 2(veth62a77d1d) entered forwarding state1691machine # [ 54.016247] dhcpcd[601]: veth62a77d1d: waiting for carrier1692machine # [ 54.018233] dhcpcd[601]: veth6f88f01c: soliciting an IPv6 router1693machine # [ 54.021100] dhcpcd[601]: veth62a77d1d: carrier acquired1694machine # [ 54.040132] dhcpcd[601]: veth62a77d1d: IAID 6a:aa:ee:8e1695machine # [ 54.041860] dhcpcd[601]: veth62a77d1d: adding address fe80::e095:6aff:feaa:ee8e1696machine # [ 54.164875] systemd[1]: Started libcontainer container f9f005b5b91d1a4ebdcd27103687735e471c696e372da8b9ba39ccabac32a1bc.1697machine # Error from server (NotFound): namespaces "niks3" not found1698machine # [ 55.179989] k3s[815]: I0827 17:08:18.936801 815 alloc.go:329] "allocated clusterIPs" service="niks3/niks3" clusterIPs={"IPv4":"10.43.176.190"}1699machine # [ 55.211699] k3s[815]: I0827 17:08:18.968806 815 controller.go:667] quota admission added evaluator for: cronjobs.batch1700machine # [ 55.226954] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount1300675387.mount: Deactivated successfully.1701machine # [ 55.276877] systemd[1]: cri-containerd-4f5e958d6ea0d53a1ac461338223a1c40498d29d8d311535f06fd880d40534ca.scope: Deactivated successfully.1702machine # [ 55.279839] systemd[1]: cri-containerd-4f5e958d6ea0d53a1ac461338223a1c40498d29d8d311535f06fd880d40534ca.scope: Consumed 821ms CPU time over 1.552s wall clock time, 40.6M memory peak, 4.1M incoming IP traffic, 78.3K outgoing IP traffic.1703machine # [ 55.308700] systemd[1]: Started libcontainer container a6f156e3f87bd5deab9418e7fec135e42880194d3f803e328b4552145bb49a25.1704machine # [ 55.348561] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-4f5e958d6ea0d53a1ac461338223a1c40498d29d8d311535f06fd880d40534ca-rootfs.mount: Deactivated successfully.1705machine # [ 55.454565] k3s[815]: I0827 17:08:19.211630 815 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/helm-install-niks3-nwfx8" podStartSLOduration=20.2115643 podStartE2EDuration="20.2115643s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-08-27 17:07:59 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-08-27 17:08:17.8350609 +0000 UTC m=+31.444643841" watchObservedRunningTime="2026-08-27 17:08:19.2115643 +0000 UTC m=+32.821147241"1706machine # [ 55.532945] systemd[1]: Created slice libcontainer container kubepods-besteffort-podb8c988fe_347a_46f3_ac26_684b5fe3e19e.slice.1707machine # [ 55.564594] k3s[815]: I0827 17:08:19.321935 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"s3\" (UniqueName: \"kubernetes.io/secret/b8c988fe-347a-46f3-ac26-684b5fe3e19e-s3\") pod \"niks3-5967c99c74-hg72v\" (UID: \"b8c988fe-347a-46f3-ac26-684b5fe3e19e\") " pod="niks3/niks3-5967c99c74-hg72v"1708machine # [ 55.569711] k3s[815]: I0827 17:08:19.326693 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"oidc\" (UniqueName: \"kubernetes.io/configmap/b8c988fe-347a-46f3-ac26-684b5fe3e19e-oidc\") pod \"niks3-5967c99c74-hg72v\" (UID: \"b8c988fe-347a-46f3-ac26-684b5fe3e19e\") " pod="niks3/niks3-5967c99c74-hg72v"1709machine # [ 55.574454] k3s[815]: I0827 17:08:19.326785 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/b8c988fe-347a-46f3-ac26-684b5fe3e19e-token\") pod \"niks3-5967c99c74-hg72v\" (UID: \"b8c988fe-347a-46f3-ac26-684b5fe3e19e\") " pod="niks3/niks3-5967c99c74-hg72v"1710machine # [ 55.579606] k3s[815]: I0827 17:08:19.326806 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"db\" (UniqueName: \"kubernetes.io/secret/b8c988fe-347a-46f3-ac26-684b5fe3e19e-db\") pod \"niks3-5967c99c74-hg72v\" (UID: \"b8c988fe-347a-46f3-ac26-684b5fe3e19e\") " pod="niks3/niks3-5967c99c74-hg72v"1711machine # [ 55.584367] k3s[815]: I0827 17:08:19.326826 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-sz42n\" (UniqueName: \"kubernetes.io/projected/b8c988fe-347a-46f3-ac26-684b5fe3e19e-kube-api-access-sz42n\") pod \"niks3-5967c99c74-hg72v\" (UID: \"b8c988fe-347a-46f3-ac26-684b5fe3e19e\") " pod="niks3/niks3-5967c99c74-hg72v"1712machine # [ 55.908963] dhcpcd[601]: veth62a77d1d: soliciting a DHCP lease1713machine # [ 56.127788] k3s[815]: I0827 17:08:19.884919 815 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/coredns-c5fdd76cf-fcmv5" podStartSLOduration=20.88487824 podStartE2EDuration="20.88487824s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-08-27 17:07:59 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-08-27 17:08:19.88210152 +0000 UTC m=+33.491684501" watchObservedRunningTime="2026-08-27 17:08:19.88487824 +0000 UTC m=+33.494461201"1714machine # [ 56.263110] cni0: port 3(veth8f72dde6) entered blocking state1715machine # [ 56.264169] cni0: port 3(veth8f72dde6) entered disabled state1716machine # [ 56.264300] veth8f72dde6: entered allmulticast mode1717machine # [ 56.264531] veth8f72dde6: entered promiscuous mode1718machine # [ 56.285959] cni0: port 3(veth8f72dde6) entered blocking state1719machine # [ 56.286099] cni0: port 3(veth8f72dde6) entered forwarding state1720machine # [ 56.400229] (udev-worker)[1831]: Network interface NamePolicy= disabled on kernel command line.1721machine # [ 56.456356] dhcpcd[601]: veth8f72dde6: IAID 35:77:a4:c01722machine # [ 56.457856] dhcpcd[601]: veth8f72dde6: adding address fe80::a0c0:35ff:fe77:a4c01723machine # [ 56.488930] systemd[1]: Started libcontainer container cf6257bfec3a7f4c2ccca43fd1a1faa32cd5a5be61e5c6d05d506420028e5fef.1724machine # [ 56.875226] dhcpcd[601]: veth62a77d1d: soliciting an IPv6 router1725machine # [ 56.925315] dhcpcd[601]: veth8f72dde6: soliciting a DHCP lease1726machine # [ 56.993644] systemd[1]: Started libcontainer container 4923f59f251ca4e66e118279ed56381bd8fb245bd2efe70e099a58f143358b8d.1727machine # [ 57.135322] systemd[1]: cri-containerd-74cd0a405ee3c626d14f336c2e6b88839e7c08f21ee04325d70c67c2ebb094b4.scope: Deactivated successfully.1728machine # [ 57.177946] postgres[1920]: [1920] ERROR: relation "goose_db_version" does not exist at character 361729machine # [ 57.180911] postgres[1920]: [1920] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1730machine # [ 57.215299] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount2820235090.mount: Deactivated successfully.1731machine # [ 57.222052] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-74cd0a405ee3c626d14f336c2e6b88839e7c08f21ee04325d70c67c2ebb094b4-rootfs.mount: Deactivated successfully.1732machine # [ 57.228462] dhcpcd[601]: veth6f88f01c: probing for an IPv4LL address1733machine # [ 57.343866] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-74cd0a405ee3c626d14f336c2e6b88839e7c08f21ee04325d70c67c2ebb094b4-shm.mount: Deactivated successfully.1734machine # [ 57.411155] cni0: port 1(veth6f88f01c) entered disabled state1735machine # [ 57.413796] veth6f88f01c (unregistering): left allmulticast mode1736machine # [ 57.413870] veth6f88f01c (unregistering): left promiscuous mode1737machine # [ 57.409370] dhcpcd[601]: veth6f88f01c: carrier lost[ 57.413914] cni0: port 1(veth6f88f01c) entered disabled state1738machine # 1739machine # [ 57.448828] systemd[1]: run-netns-cni\x2d020b1b84\x2d86bf\x2db42d\x2deb90\x2dfe24e42cc0c4.mount: Deactivated successfully.1740machine # [ 57.489502] dhcpcd[601]: veth6f88f01c: deleting address fe80::1456:3dff:fe90:ca961741machine # [ 57.568522] dhcpcd[601]: veth6f88f01c: removing interface1742machine # [ 57.601062] k3s[815]: I0827 17:08:21.357557 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-kube-api-access-nc6jc\" (UniqueName: \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-kube-api-access-nc6jc\") pod \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") "1743machine # [ 57.615865] k3s[815]: I0827 17:08:21.357628 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-tmp\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-tmp\") pod \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") "1744machine # [ 57.631162] k3s[815]: I0827 17:08:21.357664 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-cache\") pod \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") "1745machine # [ 57.642750] k3s[815]: I0827 17:08:21.357692 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-values\" (UniqueName: \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-values\") pod \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") "1746machine # [ 57.652098] k3s[815]: I0827 17:08:21.357712 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/configmap/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-content\" (UniqueName: \"kubernetes.io/configmap/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-content\") pod \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") "1747machine # [ 57.660151] k3s[815]: I0827 17:08:21.357740 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-helm\") pod \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") "1748machine # [ 57.667460] k3s[815]: I0827 17:08:21.357758 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-config\") pod \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\" (UID: \"64a48f06-1cc7-4e9f-99a5-2d6d346e416b\") "1749machine # [ 57.674387] k3s[815]: I0827 17:08:21.375939 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/configmap/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-content" pod "64a48f06-1cc7-4e9f-99a5-2d6d346e416b" (UID: "64a48f06-1cc7-4e9f-99a5-2d6d346e416b"). InnerVolumeSpecName "content". PluginName "kubernetes.io/configmap", VolumeGIDValue ""1750machine # [ 57.680202] k3s[815]: I0827 17:08:21.376644 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-config" pod "64a48f06-1cc7-4e9f-99a5-2d6d346e416b" (UID: "64a48f06-1cc7-4e9f-99a5-2d6d346e416b"). InnerVolumeSpecName "klipper-config". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1751machine # [ 57.685649] k3s[815]: I0827 17:08:21.377035 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-cache" pod "64a48f06-1cc7-4e9f-99a5-2d6d346e416b" (UID: "64a48f06-1cc7-4e9f-99a5-2d6d346e416b"). InnerVolumeSpecName "klipper-cache". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1752machine # [ 57.690918] k3s[815]: I0827 17:08:21.389432 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-values" pod "64a48f06-1cc7-4e9f-99a5-2d6d346e416b" (UID: "64a48f06-1cc7-4e9f-99a5-2d6d346e416b"). InnerVolumeSpecName "values". PluginName "kubernetes.io/projected", VolumeGIDValue ""1753machine # [ 57.695925] k3s[815]: I0827 17:08:21.400688 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-helm" pod "64a48f06-1cc7-4e9f-99a5-2d6d346e416b" (UID: "64a48f06-1cc7-4e9f-99a5-2d6d346e416b"). InnerVolumeSpecName "klipper-helm". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1754machine # [ 57.700938] k3s[815]: I0827 17:08:21.400931 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-kube-api-access-nc6jc" pod "64a48f06-1cc7-4e9f-99a5-2d6d346e416b" (UID: "64a48f06-1cc7-4e9f-99a5-2d6d346e416b"). InnerVolumeSpecName "kube-api-access-nc6jc". PluginName "kubernetes.io/projected", VolumeGIDValue ""1755machine # [ 57.705712] k3s[815]: I0827 17:08:21.401026 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-tmp" pod "64a48f06-1cc7-4e9f-99a5-2d6d346e416b" (UID: "64a48f06-1cc7-4e9f-99a5-2d6d346e416b"). InnerVolumeSpecName "tmp". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1756machine # [ 57.710478] systemd[1]: var-lib-kubelet-pods-64a48f06\x2d1cc7\x2d4e9f\x2d99a5\x2d2d6d346e416b-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dconfig.mount: Deactivated successfully.1757machine # [ 57.712767] k3s[815]: I0827 17:08:21.458185 815 reconciler_common.go:299] "Volume detached for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-cache\") on node \"machine\" DevicePath \"\""1758machine # [ 57.715802] k3s[815]: I0827 17:08:21.458239 815 reconciler_common.go:299] "Volume detached for volume \"values\" (UniqueName: \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-values\") on node \"machine\" DevicePath \"\""1759machine # [ 57.718863] k3s[815]: I0827 17:08:21.458256 815 reconciler_common.go:299] "Volume detached for volume \"content\" (UniqueName: \"kubernetes.io/configmap/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-content\") on node \"machine\" DevicePath \"\""1760machine # [ 57.721771] k3s[815]: I0827 17:08:21.458272 815 reconciler_common.go:299] "Volume detached for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-helm\") on node \"machine\" DevicePath \"\""1761machine # [ 57.724708] k3s[815]: I0827 17:08:21.458288 815 reconciler_common.go:299] "Volume detached for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-klipper-config\") on node \"machine\" DevicePath \"\""1762machine # [ 57.727622] k3s[815]: I0827 17:08:21.458305 815 reconciler_common.go:299] "Volume detached for volume \"kube-api-access-nc6jc\" (UniqueName: \"kubernetes.io/projected/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-kube-api-access-nc6jc\") on node \"machine\" DevicePath \"\""1763machine # [ 57.731890] k3s[815]: I0827 17:08:21.458322 815 reconciler_common.go:299] "Volume detached for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/64a48f06-1cc7-4e9f-99a5-2d6d346e416b-tmp\") on node \"machine\" DevicePath \"\""1764machine # [ 57.869601] dhcpcd[601]: veth8f72dde6: soliciting an IPv6 router1765machine # [ 58.106217] k3s[815]: I0827 17:08:21.861886 815 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="74cd0a405ee3c626d14f336c2e6b88839e7c08f21ee04325d70c67c2ebb094b4"1766machine # [ 58.147110] systemd[1]: Removed slice libcontainer container kubepods-burstable-pod64a48f06_1cc7_4e9f_99a5_2d6d346e416b.slice.1767machine # [ 58.156343] systemd[1]: kubepods-burstable-pod64a48f06_1cc7_4e9f_99a5_2d6d346e416b.slice: Consumed 850ms CPU time over 20.420s wall clock time, 40.9M memory peak, 4.1M incoming IP traffic, 78.3K outgoing IP traffic.1768machine # [ 58.185403] k3s[815]: I0827 17:08:21.942583 815 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-5967c99c74-hg72v" podStartSLOduration=2.94254548 podStartE2EDuration="2.94254548s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-08-27 17:08:19 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-08-27 17:08:21.94122384 +0000 UTC m=+35.550806821" watchObservedRunningTime="2026-08-27 17:08:21.94254548 +0000 UTC m=+35.552128461"1769machine # [ 58.216599] systemd[1]: var-lib-kubelet-pods-64a48f06\x2d1cc7\x2d4e9f\x2d99a5\x2d2d6d346e416b-volumes-kubernetes.io\x7eprojected-kube\x2dapi\x2daccess\x2dnc6jc.mount: Deactivated successfully.1770machine # [ 58.224498] systemd[1]: var-lib-kubelet-pods-64a48f06\x2d1cc7\x2d4e9f\x2d99a5\x2d2d6d346e416b-volumes-kubernetes.io\x7eprojected-values.mount: Deactivated successfully.1771machine # [ 58.227856] systemd[1]: var-lib-kubelet-pods-64a48f06\x2d1cc7\x2d4e9f\x2d99a5\x2d2d6d346e416b-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dhelm.mount: Deactivated successfully.1772machine # [ 58.238957] systemd[1]: var-lib-kubelet-pods-64a48f06\x2d1cc7\x2d4e9f\x2d99a5\x2d2d6d346e416b-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dcache.mount: Deactivated successfully.1773machine # [ 58.243144] systemd[1]: var-lib-kubelet-pods-64a48f06\x2d1cc7\x2d4e9f\x2d99a5\x2d2d6d346e416b-volumes-kubernetes.io\x7eempty\x2ddir-tmp.mount: Deactivated successfully.1774machine: (finished: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s, in 27.28 seconds)1775machine: waiting for success: curl -sf http://localhost:30051/readyz | grep OK1776machine: (finished: waiting for success: curl -sf http://localhost:30051/readyz | grep OK, in 1.19 seconds)1777(finished: subtest: chart deploys and becomes ready, in 28.47 seconds)1778machine: waiting for success: kubectl -n ci get sa builder1779machine: (finished: waiting for success: kubectl -n ci get sa builder, in 0.28 seconds)1780machine: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt1781machine: (finished: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt, in 0.28 seconds)1782machine: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt1783machine: (finished: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt, in 0.34 seconds)1784machine: must succeed: readlink -f /run/current-system/sw/bin/niks31785machine: (finished: must succeed: readlink -f /run/current-system/sw/bin/niks3, in 0.04 seconds)1786subtest: allowed service account can push via workload identity1787machine: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/45vwhdrvxhjqs93q0qsdwv6a8z7cpjfi-niks3-1.9.0 2>&11788machine # [ 60.910360] dhcpcd[601]: veth62a77d1d: probing for an IPv4LL address1789machine # [ 61.925161] dhcpcd[601]: veth8f72dde6: probing for an IPv4LL address1790machine: (finished: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/45vwhdrvxhjqs93q0qsdwv6a8z7cpjfi-niks3-1.9.0 2>&1, in 1.89 seconds)1791machine: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/45vwhdrvxhjqs93q0qsdwv6a8z7cpjfi.narinfo1792machine: (finished: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/45vwhdrvxhjqs93q0qsdwv6a8z7cpjfi.narinfo, in 0.05 seconds)1793(finished: subtest: allowed service account can push via workload identity, in 1.94 seconds)1794subtest: write scope does not grant admin1795machine: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status1796machine: (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.07 seconds)1797(finished: subtest: write scope does not grant admin, in 0.07 seconds)1798subtest: other service accounts are rejected1799machine: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/45vwhdrvxhjqs93q0qsdwv6a8z7cpjfi-niks3-1.9.0 2>&11800machine: (finished: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/45vwhdrvxhjqs93q0qsdwv6a8z7cpjfi-niks3-1.9.0 2>&1, in 0.23 seconds)1801(finished: subtest: other service accounts are rejected, in 0.23 seconds)1802subtest: gc cronjob runs against the service1803machine: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual1804machine: (finished: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual, in 0.32 seconds)1805machine: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s1806machine # [ 63.053065] systemd[1]: Created slice libcontainer container kubepods-besteffort-podd67004db_5c22_49b2_be65_c0c876819e91.slice.1807machine # [ 63.071260] k3s[815]: I0827 17:08:26.828043 815 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/d67004db-5c22-49b2-be65-c0c876819e91-token\") pod \"gc-manual-z9dk4\" (UID: \"d67004db-5c22-49b2-be65-c0c876819e91\") " pod="niks3/gc-manual-z9dk4"1808machine # [ 63.434567] cni0: port 1(veth353bbaa0) entered blocking state1809machine # [ 63.434754] cni0: port 1(veth353bbaa0) entered disabled state1810machine # [ 63.434967] veth353bbaa0: entered allmulticast mode1811machine # [ 63.437386] veth353bbaa0: entered promiscuous mode1812machine # [ 63.462506] cni0: port 1(veth353bbaa0) entered blocking state1813machine # [ 63.462655] cni0: port 1(veth353bbaa0) entered forwarding state1814machine # [ 63.559479] (udev-worker)[2208]: Network interface NamePolicy= disabled on kernel command line.1815machine # [ 63.620491] systemd[1]: Started libcontainer container ea759a9dd2afe09e146999cd9487d1198c7cfe54ad82d3d2b490816c6c78167f.1816machine # [ 63.626970] dhcpcd[601]: veth353bbaa0: IAID f1:92:81:241817machine # [ 63.628657] dhcpcd[601]: veth353bbaa0: adding address fe80::2897:f1ff:fe92:81241818machine # [ 63.760505] systemd[1]: Started libcontainer container c77d6e13b5cf3713c45579ef2a48188285d631811d40c18c9a5808e74c430184.1819machine # [ 64.169199] k3s[815]: I0827 17:08:27.925311 815 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/gc-manual-z9dk4" podStartSLOduration=1.9251877400000001 podStartE2EDuration="1.92518774s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-08-27 17:08:26 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-08-27 17:08:27.92483462 +0000 UTC m=+41.534417601" watchObservedRunningTime="2026-08-27 17:08:27.92518774 +0000 UTC m=+41.534770721"1820machine # [ 64.199197] dhcpcd[601]: veth353bbaa0: soliciting a DHCP lease1821machine # [ 65.590615] dhcpcd[601]: veth353bbaa0: soliciting an IPv6 router1822machine # [ 65.786203] dhcpcd[601]: veth62a77d1d: using IPv4LL address 169.254.147.1401823machine # [ 65.790250] dhcpcd[601]: veth62a77d1d: adding route to 169.254.0.0/161824machine # [ 65.846938] systemd[1]: cri-containerd-c77d6e13b5cf3713c45579ef2a48188285d631811d40c18c9a5808e74c430184.scope: Deactivated successfully.1825machine # [ 65.853793] systemd[1]: cri-containerd-c77d6e13b5cf3713c45579ef2a48188285d631811d40c18c9a5808e74c430184.scope: Consumed 37ms CPU time over 2.085s wall clock time, 3.6M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1826machine # [ 65.928553] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-c77d6e13b5cf3713c45579ef2a48188285d631811d40c18c9a5808e74c430184-rootfs.mount: Deactivated successfully.1827machine # [ 66.757903] dhcpcd[601]: veth8f72dde6: using IPv4LL address 169.254.124.2221828machine # [ 66.759377] dhcpcd[601]: veth8f72dde6: adding route to 169.254.0.0/161829machine # [ 67.214403] systemd[1]: cri-containerd-ea759a9dd2afe09e146999cd9487d1198c7cfe54ad82d3d2b490816c6c78167f.scope: Deactivated successfully.1830machine # [ 67.313519] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-ea759a9dd2afe09e146999cd9487d1198c7cfe54ad82d3d2b490816c6c78167f-rootfs.mount: Deactivated successfully.1831machine # [ 67.362158] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-ea759a9dd2afe09e146999cd9487d1198c7cfe54ad82d3d2b490816c6c78167f-shm.mount: Deactivated successfully.1832machine # [ 67.435114] cni0: port 1(veth353bbaa0) entered disabled state1833machine # [ 67.438137] veth353bbaa0 (unregistering): left allmulticast mode1834machine # [ 67.438242] veth353bbaa0 (unregistering): left promiscuous mode1835machine # [ 67.438305] cni0: port 1(veth353bbaa0) entered disabled state1836machine # [ 67.437784] dhcpcd[601]: veth353bbaa0: carrier lost1837machine # [ 67.481260] systemd[1]: run-netns-cni\x2d1f123167\x2d66aa\x2dd35f\x2dd321\x2d4b953743822a.mount: Deactivated successfully.1838machine # [ 67.532849] dhcpcd[601]: veth353bbaa0: deleting address fe80::2897:f1ff:fe92:81241839machine # [ 67.608510] dhcpcd[601]: veth353bbaa0: removing interface1840machine # [ 67.610909] k3s[815]: I0827 17:08:31.367720 815 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/secret/d67004db-5c22-49b2-be65-c0c876819e91-token\" (UniqueName: \"kubernetes.io/secret/d67004db-5c22-49b2-be65-c0c876819e91-token\") pod \"d67004db-5c22-49b2-be65-c0c876819e91\" (UID: \"d67004db-5c22-49b2-be65-c0c876819e91\") "1841machine # [ 67.622944] systemd[1]: var-lib-kubelet-pods-d67004db\x2d5c22\x2d49b2\x2dbe65\x2dc0c876819e91-volumes-kubernetes.io\x7esecret-token.mount: Deactivated successfully.1842machine # [ 67.629264] k3s[815]: I0827 17:08:31.381816 815 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/d67004db-5c22-49b2-be65-c0c876819e91-token" pod "d67004db-5c22-49b2-be65-c0c876819e91" (UID: "d67004db-5c22-49b2-be65-c0c876819e91"). InnerVolumeSpecName "token". PluginName "kubernetes.io/secret", VolumeGIDValue ""1843machine # [ 67.636164] k3s[815]: time="2026-08-27T17:08:31Z" level=info msg="Starting network policy controller version v2.6.3-k3s1, built on 1970-01-01T01:01:01Z, go1.26.5"1844machine # [ 67.642081] k3s[815]: I0827 17:08:31.389063 815 network_policy_controller.go:164] Starting network policy controller1845machine # [ 67.711254] k3s[815]: I0827 17:08:31.468564 815 reconciler_common.go:299] "Volume detached for volume \"token\" (UniqueName: \"kubernetes.io/secret/d67004db-5c22-49b2-be65-c0c876819e91-token\") on node \"machine\" DevicePath \"\""1846machine # [ 67.979335] k3s[815]: I0827 17:08:31.736647 815 network_policy_controller.go:179] Starting network policy controller full sync goroutine1847machine # [ 68.172110] k3s[815]: I0827 17:08:31.929369 815 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="ea759a9dd2afe09e146999cd9487d1198c7cfe54ad82d3d2b490816c6c78167f"1848machine # [ 68.185087] systemd[1]: Removed slice libcontainer container kubepods-besteffort-podd67004db_5c22_49b2_be65_c0c876819e91.slice.1849machine # [ 68.187238] systemd[1]: kubepods-besteffort-podd67004db_5c22_49b2_be65_c0c876819e91.slice: Consumed 64ms CPU time over 5.131s wall clock time, 4.4M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1850machine: (finished: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s, in 5.24 seconds)1851(finished: subtest: gc cronjob runs against the service, in 5.57 seconds)1852subtest: helm test hook passes1853machine: must succeed: helm test -n niks3 niks3 --timeout 2m >&21854machine # [ 68.877920] dhcpcd[601]: veth62a77d1d: no IPv6 Routers available1855machine # [ 69.338271] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod81ad5f6f_f951_44b4_ad83_f41c66ec5402.slice.1856machine # [ 69.405002] cni0: port 1(vethb615b388) entered blocking state1857machine # [ 69.405089] cni0: port 1(vethb615b388) entered disabled state1858machine # [ 69.405170] vethb615b388: entered allmulticast mode1859machine # [ 69.402813] (udev-worker)[2393]: Network interface NamePolicy= disabled on kernel command line.[ 69.405317] vethb615b388: entered promiscuous mode1860machine # 1861machine # [ 69.428058] cni0: port 1(vethb615b388) entered blocking state1862machine # [ 69.428158] cni0: port 1(vethb615b388) entered forwarding state1863machine # [ 69.479172] dhcpcd[601]: vethb615b388: IAID 99:f5:4c:901864machine # [ 69.481328] dhcpcd[601]: vethb615b388: adding address fe80::cc1d:99ff:fef5:4c901865machine # [ 69.585051] systemd[1]: Started libcontainer container c434ce32add1baa2ecd550b23b5418b78ac66c28810dcd07bfeecf5aacd36178.1866machine # [ 69.729029] systemd[1]: Started libcontainer container 03beab7f469f024c83e76e715fe9f5bdc880bf37bf4302e650375d66bf9cbfa5.1867machine # [ 69.797084] systemd[1]: cri-containerd-03beab7f469f024c83e76e715fe9f5bdc880bf37bf4302e650375d66bf9cbfa5.scope: Deactivated successfully.1868machine # [ 69.799634] systemd[1]: cri-containerd-03beab7f469f024c83e76e715fe9f5bdc880bf37bf4302e650375d66bf9cbfa5.scope: Consumed 27ms CPU time over 67ms wall clock time, 3.6M memory peak, 693B incoming IP traffic, 547B outgoing IP traffic.1869machine # [ 69.897225] dhcpcd[601]: veth8f72dde6: no IPv6 Routers available1870machine # [ 70.369590] dhcpcd[601]: vethb615b388: soliciting a DHCP lease1871machine # [ 71.230705] systemd[1]: cri-containerd-c434ce32add1baa2ecd550b23b5418b78ac66c28810dcd07bfeecf5aacd36178.scope: Deactivated successfully.1872machine # [ 71.322583] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-c434ce32add1baa2ecd550b23b5418b78ac66c28810dcd07bfeecf5aacd36178-rootfs.mount: Deactivated successfully.1873machine # [ 71.338879] dhcpcd[601]: vethb615b388: soliciting an IPv6 router1874machine # [ 71.389950] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-c434ce32add1baa2ecd550b23b5418b78ac66c28810dcd07bfeecf5aacd36178-shm.mount: Deactivated successfully.1875machine # [ 71.471530] cni0: port 1(vethb615b388) entered disabled state1876machine # [ 71.474867] vethb615b388 (unregistering): left allmulticast mode1877machine # [ 71.474982] vethb615b388 (unregistering): left promiscuous mode1878machine # [ 71.475048] cni0: port 1(vethb615b388) entered disabled state1879machine # [ 71.472774] dhcpcd[601]: vethb615b388: carrier lost1880machine # [ 71.527682] systemd[1]: run-netns-cni\x2ded08854c\x2d726a\x2d9dd1\x2d5633\x2d5859fefe9024.mount: Deactivated successfully.1881machine # [ 71.572877] dhcpcd[601]: vethb615b388: deleting address fe80::cc1d:99ff:fef5:4c901882machine # NAME: niks31883machine # LAST DEPLOYED: Thu Aug 27 17:08:18 20261884machine # NAMESPACE: niks31885machine # STATUS: deployed1886machine # REVISION: 11887machine # DESCRIPTION: Install complete1888machine # TEST SUITE: niks3-test1889machine # Last Started: Thu Aug 27 17:08:33 20261890machine # Last Completed: Thu Aug 27 17:08:35 20261891machine # Phase: Succeeded1892machine: (finished: must succeed: helm test -n niks3 niks3 --timeout 2m >&2, in 3.38 seconds)1893(finished: subtest: helm test hook passes, in 3.38 seconds)1894(finished: run the VM test script, in 72.46 seconds)1895machine # [ 71.693682] dhcpcd[601]: vethb615b388: removing interface1896test script finished in 72.54s1897cleanup1898kill QemuMachine (pid 45)1899machine # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/41m77i1296n33p6liin8ynr6wh3h6b7m-python3-3.14.6/bin/python3.14)1900(finished: cleanup, in 0.85 seconds)1901additionally exposed symbols:1902 machine,1903 vlan1,1904 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_ssh1905time=2026-08-27T17:08:24.588Z level=INFO msg="Uploading 8 paths to localhost (0 already cached)"1906time=2026-08-27T17:08:24.589Z level=INFO msg="Uploading 84i6rp3qvbrm0vl88w5fm9h37yka5mzb-xgcc-15.3.0-libgcc (150.1KB)"1907time=2026-08-27T17:08:24.589Z level=INFO msg="Uploading 7sw8czjz2170229kjhavkx3p4rkidh1x-mailcap-2.1.54 (116.6KB)"1908time=2026-08-27T17:08:24.591Z level=INFO msg="Uploading qr7qvicd9q4lnq6lznx223z5sakp9jrx-libunistring-1.4.2 (2.0MB)"1909time=2026-08-27T17:08:24.592Z level=INFO msg="Uploading qlmazqi9rqlg4b1gbw5qj2v8pwd9bl39-libidn2-2.3.8 (366.1KB)"1910time=2026-08-27T17:08:24.592Z level=INFO msg="Uploading bknwi0mk48rvgfzggxl795lmspmmcz46-iana-etc-20251215 (557.8KB)"1911time=2026-08-27T17:08:24.593Z level=INFO msg="Uploading 45vwhdrvxhjqs93q0qsdwv6a8z7cpjfi-niks3-1.9.0 (7.1MB)"1912time=2026-08-27T17:08:24.594Z level=INFO msg="Uploading cjcj20n6xa0hs5cd0adwx47g058c6z72-glibc-2.42-67 (44.4MB)"1913time=2026-08-27T17:08:24.596Z level=INFO msg="Uploading zldvyvcxx4rwb4r1b92c34fcs634623w-tzdata-2026c (2.0MB)"1914time=2026-08-27T17:08:26.045Z level=INFO msg="Uploading 8 narinfos"1915time=2026-08-27T17:08:26.089Z level=INFO msg="Upload complete. (1.642s)"1916