vm-test-run-nixos-test-k3s
checks.aarch64-linux.nixos-test-k3s
· build #511
· raw
1tribuchet: building on eliza2[0.00s] Machine state will be reset. To keep it, pass --keep-machine-state3[0.00s] start all VLans4[0.00s] (finished: start all VLans, in 0.00 seconds)5[0.00s] Test will time out and terminate in 3600.0 seconds6[0.00s] run the VM test script7[0.01s] machine: waiting for unit k3s.service8[0.01s] machine: waiting for the VM to finish booting9[0.01s] machine: starting vm10machine # Disk image does not exist, creating the virtualisation disk image...11[0.43s] machine: QEMU running (pid 45)12machine # Formatting '/build/vm-state-machine/tmp.uhnYKOA19u', 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: c8e45c96-dd61-4c49-9d15-3d10a493bf3517machine # Superblock backups stored on blocks:18machine # 32768, 98304, 163840, 229376, 294912, 819200, 884736, 160563219machine # 20machine # Allocating group tables: 0/64 done21machine # Writing inode tables: 0/64 done22machine # Creating journal (16384 blocks): done23machine # Writing superblocks and filesystem accounting information: 0/64 done24machine # 25machine # Virtualisation disk image created.26machine # Starting virtiofs daemons...27machine # [2026-11-12T17:02:26Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)28machine # [2026-11-12T17:02:26Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether29machine # [2026-11-12T17:02:26Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)30machine # [2026-11-12T17:02:26Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether31machine # [2026-11-12T17:02:26Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)32machine # [2026-11-12T17:02:26Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether33machine # [2026-11-12T17:02:26Z INFO virtiofsd] Waiting for vhost-user socket connection...34machine # [2026-11-12T17:02:26Z INFO virtiofsd] Waiting for vhost-user socket connection...35machine # [2026-11-12T17:02:26Z INFO virtiofsd] Waiting for vhost-user socket connection...36machine # [2026-11-12T17:02:26Z INFO virtiofsd] Client connected, servicing requests37machine # [2026-11-12T17:02:26Z INFO virtiofsd] Client connected, servicing requests38machine # [2026-11-12T17:02:26Z INFO virtiofsd] Client connected, servicing requests39machine # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]40machine # [ 0.000000] Linux version 6.18.60 (nixbld@localhost) (gcc (GCC) 16.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT @179336200141machine # [ 0.000000] KASLR enabled42machine # [ 0.000000] random: crng init done43machine # [ 0.000000] Machine model: linux,dummy-virt44machine # [ 0.000000] efi: UEFI not found.45machine # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT46machine # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000ffffffff]47machine # [ 0.000000] NODE_DATA(0) allocated [mem 0xffdec0c0-0xffdef83f]48machine # [ 0.000000] Zone ranges:49machine # [ 0.000000] DMA [mem 0x0000000040000000-0x00000000ffffffff]50machine # [ 0.000000] DMA32 empty51machine # [ 0.000000] Normal empty52machine # [ 0.000000] Device empty53machine # [ 0.000000] Movable zone start for each node54machine # [ 0.000000] Early memory node ranges55machine # [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000ffffffff]56machine # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x00000000ffffffff]57machine # [ 0.000000] cma: Reserved 32 MiB at 0x00000000fac0000058machine # [ 0.000000] psci: probing for conduit method from DT.59machine # [ 0.000000] psci: PSCIv1.3 detected in firmware.60machine # [ 0.000000] psci: Using standard PSCI v0.2 function IDs61machine # [ 0.000000] psci: Trusted OS migration not required62machine # [ 0.000000] psci: SMC Calling Convention v1.163machine # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)64machine # [ 0.000000] percpu: Embedded 76 pages/cpu s187672 r8192 d115432 u31129665machine # [ 0.000000] Detected PIPT I-cache on CPU066machine # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)67machine # [ 0.000000] CPU features: detected: GICv3 CPU interface68machine # [ 0.000000] CPU features: detected: Spectre-v469machine # [ 0.000000] CPU features: detected: Spectre-BHB70machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_3871machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_2372machine # [ 0.000000] alternatives: applying boot alternatives73machine # [ 0.000000] Kernel command line: console=ttyAMA0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/8k1872ywdrb70nlzgflp255y7vfdrij4-nixos-system-machine-test/init regInfo=/nix/.ro-store/mmsy37bczw0fg3yqi2h9jsbplj5rkybv-closure-info/registration console=ttyAMA0,115200n8 console=tty074machine # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/mmsy37bczw0fg3yqi2h9jsbplj5rkybv-closure-info/registration", will be passed to user space.75machine # [ 0.000000] printk: log buffer data + meta data: 1048576 + 3670016 = 4718592 bytes76machine # [ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)77machine # [ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)78machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 3MB79machine # [ 0.000000] software IO TLB: area num 2.80machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size roundup to 4MB81machine # [ 0.000000] software IO TLB: mapped [mem 0x00000000fa200000-0x00000000fa600000] (4MB)82machine # [ 0.000000] Fallback order for Node 0: 083machine # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 78643284machine # [ 0.000000] Policy zone: DMA85machine # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off86machine # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=187machine # [ 0.000000] allocated 6291456 bytes of page_ext88machine # [ 0.000000] ftrace: allocating 75323 entries in 296 pages89machine # [ 0.000000] ftrace: allocated 296 pages with 3 groups90machine # [ 0.000000] rcu: Hierarchical RCU implementation.91machine # [ 0.000000] rcu: RCU event tracing is enabled.92machine # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=2.93machine # [ 0.000000] Trampoline variant of Tasks RCU enabled.94machine # [ 0.000000] Rude variant of Tasks RCU enabled.95machine # [ 0.000000] Tracing variant of Tasks RCU enabled.96machine # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.97machine # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=298machine # [ 0.000000] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.99machine # [ 0.000000] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.100machine # [ 0.000000] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.101machine # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0102machine # [ 0.000000] GICv3: 256 SPIs implemented103machine # [ 0.000000] GICv3: 0 Extended SPIs implemented104machine # [ 0.000000] Root IRQ handler: gic_handle_irq105machine # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI106machine # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0107machine # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000108machine # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]109machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @45500000 (indirect, esz 8, psz 64K, shr 1)110machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @45510000 (flat, esz 8, psz 64K, shr 1)111machine # [ 0.000000] GICv3: using LPI property table @0x0000000045530000112machine # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000045540000113machine # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.114machine # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns115machine # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).116machine # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns117machine # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns118machine # [ 0.000034] arm-pv: using stolen time PV119machine # [ 0.000417] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)120machine # [ 0.000635] Console: colour dummy device 80x25121machine # [ 0.000644] printk: legacy console [tty0] enabled122machine # [ 0.000845] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)123machine # [ 0.000852] pid_max: default: 32768 minimum: 301124machine # [ 0.000962] LSM: initializing lsm=lockdown,capability,landlock,yama,bpf,ima125machine # [ 0.001102] landlock: Up and running.126machine # [ 0.001106] Yama: becoming mindful.127machine # [ 0.001535] LSM support for eBPF active128machine # [ 0.001698] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)129machine # [ 0.001770] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)130machine # [ 0.003727] rcu: Hierarchical SRCU implementation.131machine # [ 0.003733] rcu: Max phase no-delay instances is 1000.132machine # [ 0.003896] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level133machine # [ 0.005035] fsl-mc MSI: its@8080000 domain created134machine # [ 0.005159] EFI services will not be available.135machine # [ 0.005303] smp: Bringing up secondary CPUs ...136machine # [ 0.005923] Detected PIPT I-cache on CPU1137machine # [ 0.005989] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000138machine # [ 0.006065] GICv3: CPU1: using allocated LPI pending table @0x0000000045550000139machine # [ 0.006142] CPU1: Booted secondary processor 0x0000000001 [0xc00fac40]140machine # [ 0.006510] smp: Brought up 1 node, 2 CPUs141machine # [ 0.006527] SMP: Total of 2 processors activated.142machine # [ 0.006529] CPU: All CPU(s) started at EL1143machine # [ 0.006538] CPU features: detected: Branch Target Identification144machine # [ 0.006542] CPU features: detected: ARMv8.4 Translation Table Level145machine # [ 0.006544] CPU features: detected: Instruction cache invalidation not required for I/D coherence146machine # [ 0.006548] CPU features: detected: Data cache clean to the PoU not required for I/D coherence147machine # [ 0.006552] CPU features: detected: Common not Private translations148machine # [ 0.006554] CPU features: detected: CRC32 instructions149machine # [ 0.006557] CPU features: detected: Data cache clean to Point of Deep Persistence150machine # [ 0.006560] CPU features: detected: Data cache clean to Point of Persistence151machine # [ 0.006563] CPU features: detected: Data independent timing control (DIT)152machine # [ 0.006566] CPU features: detected: E0PD153machine # [ 0.006568] CPU features: detected: Enhanced Counter Virtualization154machine # [ 0.006571] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)155machine # [ 0.006574] CPU features: detected: Enhanced Virtualization Traps156machine # [ 0.006577] CPU features: detected: Fine Grained Traps157machine # [ 0.006580] CPU features: detected: Generic authentication (architected QARMA5 algorithm)158machine # [ 0.006583] CPU features: detected: RCpc load-acquire (LDAPR)159machine # [ 0.006589] CPU features: detected: LSE atomic instructions160machine # [ 0.006592] CPU features: detected: Privileged Access Never161machine # [ 0.006594] CPU features: detected: PMUv3162machine # [ 0.006597] CPU features: detected: RAS Extension Support163machine # [ 0.006600] CPU features: detected: RASv1p1 Extension Support164machine # [ 0.006602] CPU features: detected: Random Number Generator165machine # [ 0.006605] CPU features: detected: Speculation barrier (SB)166machine # [ 0.006607] CPU features: detected: Stage-2 Force Write-Back167machine # [ 0.006610] CPU features: detected: TLB range maintenance instructions168machine # [ 0.006614] CPU features: detected: Speculative Store Bypassing Safe (SSBS)169machine # [ 0.006678] alternatives: applying system-wide alternatives170machine # [ 0.009830] CPU features: detected: BBM Level 2 without TLB conflict abort171machine # [ 0.010036] Memory: 2938464K/3145728K available (24640K kernel code, 10246K rwdata, 26664K rodata, 7808K init, 2086K bss, 160580K reserved, 32768K cma-reserved)172machine # [ 0.011053] devtmpfs: initialized173machine # [ 0.013626] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)174machine # [ 0.013672] futex hash table entries: 512 (32768 bytes on 1 NUMA nodes, total 32 KiB, linear).175machine # [ 0.013901] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL176machine # [ 0.013912] 0 pages in range for non-PLT usage177machine # [ 0.013914] 506368 pages in range for PLT usage178machine # [ 0.014047] pinctrl core: initialized pinctrl subsystem179machine # [ 0.014955] DMI not present or invalid.180machine # [ 0.018605] NET: Registered PF_NETLINK/PF_ROUTE protocol family181machine # [ 0.021142] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations182machine # [ 0.021443] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations183machine # [ 0.021771] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations184machine # [ 0.021797] audit: initializing netlink subsys (disabled)185machine # [ 0.022306] audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1186machine # [ 0.023723] thermal_sys: Registered thermal governor 'fair_share'187machine # [ 0.023730] thermal_sys: Registered thermal governor 'bang_bang'188machine # [ 0.023739] thermal_sys: Registered thermal governor 'step_wise'189machine # [ 0.023743] thermal_sys: Registered thermal governor 'user_space'190machine # [ 0.023747] thermal_sys: Registered thermal governor 'power_allocator'191machine # [ 0.023836] cpuidle: using governor ladder192machine # [ 0.023862] cpuidle: using governor menu193machine # [ 0.024307] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.194machine # [ 0.024375] ASID allocator initialised with 65536 entries195machine # [ 0.026383] Serial: AMBA PL011 UART driver196machine # [ 0.035952] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1197machine # [ 0.036102] printk: console [ttyAMA0] enabled198machine # [ 0.195305] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages199machine # [ 0.195323] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page200machine # [ 0.195329] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages201machine # [ 0.195333] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page202machine # [ 0.195337] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages203machine # [ 0.195342] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page204machine # [ 0.195346] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages205machine # [ 0.195350] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page206machine # [ 0.212031] fbcon: Taking over console207machine # [ 0.212054] ACPI: Interpreter disabled.208machine # [ 0.214280] iommu: Default domain type: Translated209machine # [ 0.214294] iommu: DMA domain TLB invalidation policy: strict mode210machine # [ 0.219251] SCSI subsystem initialized211machine # [ 0.219749] usbcore: registered new interface driver usbfs212machine # [ 0.219854] usbcore: registered new interface driver hub213machine # [ 0.219899] usbcore: registered new device driver usb214machine # [ 0.220393] pps_core: LinuxPPS API ver. 1 registered215machine # [ 0.220399] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>216machine # [ 0.220412] PTP clock support registered217machine # [ 0.220475] EDAC MC: Ver: 3.0.0218machine # [ 0.220796] scmi_core: SCMI protocol bus registered219machine # [ 0.223674] FPGA manager framework220machine # [ 0.224600] vgaarb: loaded221machine # [ 0.225332] clocksource: Switched to clocksource arch_sys_counter222machine # [ 0.226341] VFS: Disk quotas dquot_6.6.0223machine # [ 0.226383] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)224machine # [ 0.229910] netfs: FS-Cache loaded225machine # [ 0.230138] pnp: PnP ACPI: disabled226machine # [ 0.235494] NET: Registered PF_INET protocol family227machine # [ 0.236302] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)228machine # [ 0.278703] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)229machine # [ 0.278764] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)230machine # [ 0.278811] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)231machine # [ 0.279004] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)232machine # [ 0.279359] TCP: Hash tables configured (established 32768 bind 32768)233machine # [ 0.279515] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear)234machine # [ 0.279573] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)235machine # [ 0.279651] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)236machine # [ 0.279849] NET: Registered PF_UNIX/PF_LOCAL protocol family237machine # [ 0.279872] NET: Registered PF_XDP protocol family238machine # [ 0.279892] PCI: CLS 0 bytes, default 64239machine # [ 0.280137] Trying to unpack rootfs image as initramfs...240machine # [ 0.285615] kvm [1]: HYP mode not available241machine # [ 0.351927] Initialise system trusted keyrings242machine # [ 0.351982] Key type blacklist registered243machine # [ 0.354581] workingset: timestamp_bits=42 max_order=20 bucket_order=0244machine # [ 0.355006] squashfs: version 4.0 (2009/01/31) Phillip Lougher245machine # [ 0.355064] 9p: Installing v9fs 9p2000 file system support246machine # [ 0.355192] integrity: Platform Keyring initialized247machine # [ 0.355203] integrity: Machine keyring initialized248machine # [ 0.370811] Key type asymmetric registered249machine # [ 0.370818] Asymmetric key parser 'x509' registered250machine # [ 0.370876] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)251machine # [ 0.371013] io scheduler mq-deadline registered252machine # [ 0.371019] io scheduler kyber registered253machine # [ 0.385459] pl061_gpio 9030000.pl061: PL061 GPIO chip registered254machine # [ 0.393379] ledtrig-cpu: registered to indicate activity on CPUs255machine # [ 0.393939] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:256machine # [ 0.393959] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000257machine # [ 0.393972] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000258machine # [ 0.393979] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000259machine # [ 0.394010] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits260machine # [ 0.394046] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]261machine # [ 0.394188] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00262machine # [ 0.394199] pci_bus 0000:00: root bus resource [bus 00-ff]263machine # [ 0.394203] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]264machine # [ 0.394207] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]265machine # [ 0.394211] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]266machine # [ 0.394338] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint267machine # [ 0.394908] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint268machine # [ 0.395150] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]269machine # [ 0.395165] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]270machine # [ 0.395198] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]271machine # [ 0.395214] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]272machine # [ 0.395818] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint273machine # [ 0.396051] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]274machine # [ 0.396066] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]275machine # [ 0.396098] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]276machine # [ 0.396716] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint277machine # [ 0.396950] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]278machine # [ 0.396964] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]279machine # [ 0.396997] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]280machine # [ 0.405813] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint281machine # [ 0.406075] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]282machine # [ 0.406096] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]283machine # [ 0.406123] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]284machine # [ 0.406135] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]285machine # [ 0.406723] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint286machine # [ 0.406937] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]287machine # [ 0.406963] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]288machine # [ 0.407553] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint289machine # [ 0.407839] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]290machine # [ 0.407866] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]291machine # [ 0.408380] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint292machine # [ 0.408655] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]293machine # [ 0.408910] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint294machine # [ 0.409184] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]295machine # [ 0.409212] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]296machine # [ 0.409824] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint297machine # [ 0.410042] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]298machine # [ 0.410072] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]299machine # [ 0.410591] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint300machine # [ 0.410851] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]301machine # [ 0.410878] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]302machine # [ 0.411518] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint303machine # [ 0.411863] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]304machine # [ 0.411876] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]305machine # [ 0.411902] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]306machine # [ 0.412515] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint307machine # [ 0.412765] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]308machine # [ 0.412777] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]309machine # [ 0.412803] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]310machine # [ 0.421687] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned311machine # [ 0.421713] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned312machine # [ 0.421717] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned313machine # [ 0.421800] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned314machine # [ 0.421854] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned315machine # [ 0.421915] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned316machine # [ 0.421961] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned317machine # [ 0.422009] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned318machine # [ 0.422061] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned319machine # [ 0.422107] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned320machine # [ 0.422159] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned321machine # [ 0.422220] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned322machine # [ 0.422340] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned323machine # [ 0.422397] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned324machine # [ 0.422416] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned325machine # [ 0.422438] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned326machine # [ 0.422456] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned327machine # [ 0.422474] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned328machine # [ 0.422492] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned329machine # [ 0.422510] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned330machine # [ 0.422531] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned331machine # [ 0.422554] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned332machine # [ 0.422573] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned333machine # [ 0.422596] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned334machine # [ 0.422615] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned335machine # [ 0.422632] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned336machine # [ 0.422649] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned337machine # [ 0.422670] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned338machine # [ 0.422694] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned339machine # [ 0.422711] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned340machine # [ 0.422729] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned341machine # [ 0.422758] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]342machine # [ 0.422764] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]343machine # [ 0.422767] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]344machine # [ 0.423991] pci 0000:00:07.0: enabling device (0000 -> 0002)345machine # [ 0.453533] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)346machine # [ 0.455732] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)347machine # [ 0.465696] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)348machine # [ 0.467941] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)349machine # [ 0.470369] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)350machine # [ 0.472554] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)351machine # [ 0.482812] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)352machine # [ 0.484842] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)353machine # [ 0.486974] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)354machine # [ 0.489141] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)355machine # [ 0.499185] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)356machine # [ 0.510856] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled357machine # [ 0.512994] msm_serial: driver initialized358machine # [ 0.513133] SuperH (H)SCI(F) driver initialized359machine # [ 0.513201] STM32 USART driver initialized360machine # [ 0.548554] loop: module loaded361machine # [ 0.548832] virtio_blk virtio2: 2/0/0 default/read/poll queues362machine # [ 0.551719] virtio_blk virtio2: [vda] 16777216 512-byte logical blocks (8.59 GB/8.00 GiB)363machine # [ 0.555486] megasas: 07.734.00.00-rc1364machine # [ 0.556330] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]365machine # [ 0.568072] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000366machine # [ 0.568100] Intel/Sharp Extended Query Table at 0x0031367machine # [ 0.572535] Using buffer write method368machine # [ 0.572623] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]369machine # [ 0.576681] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000370machine # [ 0.576708] Intel/Sharp Extended Query Table at 0x0031371machine # [ 0.581421] Using buffer write method372machine # [ 0.581443] Concatenating MTD devices:373machine # [ 0.581446] (0): "0.flash"374machine # [ 0.581449] (1): "0.flash"375machine # [ 0.581452] into device "0.flash"376machine # [ 0.801269] Freeing initrd memory: 25244K377machine # [ 0.811763] tun: Universal TUN/TAP device driver, 1.6378machine # [ 0.817249] thunder_xcv, ver 1.0379machine # [ 0.817295] thunder_bgx, ver 1.0380machine # [ 0.817324] nicpf, ver 1.0381machine # [ 0.818811] e1000: Intel(R) PRO/1000 Network Driver382machine # [ 0.818820] e1000: Copyright (c) 1999-2006 Intel Corporation.383machine # [ 0.818864] e1000e: Intel(R) PRO/1000 Network Driver384machine # [ 0.818873] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.385machine # [ 0.818912] igb: Intel(R) Gigabit Ethernet Network Driver386machine # [ 0.818918] igb: Copyright (c) 2007-2014 Intel Corporation.387machine # [ 0.818949] igbvf: Intel(R) Gigabit Virtual Function Network Driver388machine # [ 0.818955] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.389machine # [ 0.819198] sky2: driver version 1.30390machine # [ 0.822073] usbcore: registered new interface driver usb-storage391machine # [ 0.822087] ehci-pci 0000:00:07.0: EHCI Host Controller392machine # [ 0.822116] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1393machine # [ 0.822205] usbcore: registered new interface driver usbserial_generic394machine # [ 0.822229] usbserial: USB Serial support registered for generic395machine # [ 0.822350] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000396machine # [ 0.823209] hv_vmbus: registering driver hyperv_keyboard397machine # [ 0.824625] rtc-pl031 9010000.pl031: registered as rtc0398machine # [ 0.824660] rtc-pl031 9010000.pl031: setting system clock to 2026-11-12T17:02:27 UTC (1794502947)399machine # [ 0.825199] i2c_dev: i2c /dev entries driver400machine # [ 0.830511] sdhci: Secure Digital Host Controller Interface driver401machine # [ 0.830522] sdhci: Copyright(c) Pierre Ossman402machine # [ 0.830986] Synopsys Designware Multimedia Card Interface Driver403machine # [ 0.831616] sdhci-pltfm: SDHCI platform and OF driver helper404machine # [ 0.834267] hid: raw HID events driver (C) Jiri Kosina405machine # [ 0.834800] usbcore: registered new interface driver usbhid406machine # [ 0.834807] usbhid: USB HID core driver407machine # [ 0.836570] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00408machine # [ 0.837132] hub 1-0:1.0: USB hub found409machine # [ 0.837236] hub 1-0:1.0: 6 ports detected410machine # [ 0.837929] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available411machine # [ 0.840535] drop_monitor: Initializing network drop monitor service412machine # [ 0.840763] NET: Registered PF_INET6 protocol family413machine # [ 0.842063] Segment Routing with IPv6414machine # [ 0.842083] In-situ OAM (IOAM) with IPv6415machine # [ 0.842119] NET: Registered PF_PACKET protocol family416machine # [ 0.842245] 9pnet: Installing 9P2000 support417machine # [ 0.842324] Key type dns_resolver registered418machine # [ 0.852644] registered taskstats version 1419machine # [ 0.852864] Loading compiled-in X.509 certificates420machine # [ 0.867218] Demotion targets for Node 0: null421machine # [ 0.867428] Key type .fscrypt registered422machine # [ 0.867434] Key type fscrypt-provisioning registered423machine # [ 0.867575] ima: No TPM chip found, activating TPM-bypass!424machine # [ 0.867600] ima: Allocated hash algorithm: sha1425machine # [ 0.867623] ima: No architecture policies found426machine # [ 0.868565] input: gpio-keys as /devices/platform/gpio-keys/input/input0427machine # [ 0.888044] clk: Disabling unused clocks428machine # [ 0.888064] PM: genpd: Disabling unused power domains429machine # [ 0.893900] Freeing unused kernel memory: 7808K430machine # [ 0.894137] Run /init as init process431machine # [ 0.912685] systemd[1]: Successfully made /usr/ read-only.432machine # [ 1.089380] usb 1-1: new high-speed USB device number 2 using ehci-pci433machine # [ 1.239155] input: QEMU QEMU USB Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:07.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input1434machine # [ 1.246780] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)435machine # [ 1.246809] systemd[1]: Detected virtualization qemu.436machine # [ 1.246889] systemd[1]: Detected architecture arm64.437machine # [ 1.246898] systemd[1]: Running in initrd.438machine # [ 1.247406] systemd[1]: Initializing machine ID from random generator.439machine # [ 1.247558] systemd[1]: Hostname set to <machine>.440machine # [ 1.348301] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0441machine # [ 1.374216] systemd[1]: bpf-restrict-fs: LSM BPF program attached442machine # [ 1.424600] systemd[1]: Queued start job for default target Initrd Default Target.443machine # [ 1.440523] systemd[1]: Created slice Slice /system/modprobe.444machine # [ 1.440835] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.445machine # [ 1.440879] systemd[1]: Expecting device /dev/disk/by-label/nixos...446machine # [ 1.440910] systemd[1]: Reached target Path Units.447machine # [ 1.440929] systemd[1]: Reached target Slice Units.448machine # [ 1.440950] systemd[1]: Reached target Swaps.449machine # [ 1.440971] systemd[1]: Reached target Timer Units.450machine # [ 1.441175] systemd[1]: Listening on D-Bus System Message Bus Socket.451machine # [ 1.441452] systemd[1]: Listening on Journal Socket (/dev/log).452machine # [ 1.441630] systemd[1]: Listening on Journal Sockets.453machine # [ 1.441737] systemd[1]: Listening on udev Kernel Socket.454machine # [ 1.441978] systemd[1]: Listening on udev Varlink Socket.455machine # [ 1.442001] systemd[1]: Reached target Socket Units.456machine # [ 1.443992] systemd[1]: Starting Create List of Static Device Nodes...457machine # [ 1.444078] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs458machine # [ 1.450523] systemd[1]: Mounting Kernel Configuration File System...459machine # [ 1.463046] systemd[1]: Starting Journal Service...460machine # [ 1.465397] usb 1-2: new high-speed USB device number 3 using ehci-pci461machine # [ 1.465536] systemd[1]: Starting Load Kernel Modules...462machine # [ 1.465668] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os463machine # [ 1.493742] systemd[1]: Starting Coldplug All udev Devices...464machine # [ 1.495439] dm_mod: module verification failed: signature and/or required key missing - tainting kernel465machine # [ 1.499563] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.466machine # [ 1.503091] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev467machine # [ 1.503121] systemd[1]: Finished Create List of Static Device Nodes.468machine # [ 1.504196] systemd[1]: Mounted Kernel Configuration File System.469machine # [ 1.510370] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0470machine # [ 1.510656] [drm] features: -virgl +edid -resource_blob -host_visible471machine # [ 1.510660] [drm] features: -context_init472machine # [ 1.511644] [drm] number of scanouts: 1473machine # [ 1.511658] [drm] number of cap sets: 0474machine # [ 1.519242] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic475machine # [ 1.519259] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0476machine # [ 1.525627] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...477machine # [ 1.526328] systemd-journald[79]: Collecting audit messages is disabled.478machine # [ 1.540760] Console: switching to colour frame buffer device 160x50479machine # [ 1.554023] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device480machine # [ 1.565762] systemd-modules-load[80]: Using 2 probe threads481machine # [ 1.567607] systemd-modules-load[80]: Module 'virtio_balloon' is built in[ 1.570191] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.482machine # [ 1.570964] systemd[1]: Started Journal Service.483machine # 484machine # [ 1.570588] systemd-modules-load[80]: Module 'virtio_console' is built in485machine # [ 1.571743] systemd-modules-load[80]: Inserted module 'dm_mod'486machine # [ 1.572863] systemd-modules-load[80]: Module 'virtio_rng' is built in487machine # [ 1.573914] systemd-modules-load[80]: Inserted module 'virtio_gpu'488machine # [ 1.574930] systemd[1]: Finished Load Kernel Modules.489machine # [ 1.576376] systemd[1]: Starting Apply Kernel Variables...490machine # [ 1.579432] systemd[1]: Starting Create Static Device Nodes in /dev...491machine # [ 1.613104] systemd[1]: Finished Create Static Device Nodes in /dev.492machine # [ 1.615266] systemd[1]: Finished Apply Kernel Variables.493machine # [ 1.617826] systemd[1]: Reached target Preparation for Local File Systems.494machine # [ 1.620213] systemd[1]: Reached target Local File Systems.495machine # [ 1.629102] input: QEMU QEMU USB Tablet as /devices/platform/4010000000.pcie/pci0000:00/0000:00:07.0/usb1/1-2/1-2:1.0/0003:0627:0001.0002/input/input2496machine # [ 1.624370] systemd[1]: Starting Create System Files and Directories...497machine # [ 1.633283] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0498machine # [ 1.629406] systemd[1]: Starting Rule-based Manager for Device Events and Files...499machine # [ 1.680633] systemd[1]: Finished Create System Files and Directories.500machine # [ 1.695767] systemd-udevd[95]: Using default interface naming scheme 'v261'.501machine # [ 1.709000] systemd[1]: Started Rule-based Manager for Device Events and Files.502machine # [ 1.767149] systemd[1]: Starting Virtual Console Setup...503machine # [ 1.802705] systemd-vconsole-setup[110]: Configuration of first virtual console was skipped, ignoring remaining ones.504machine # [ 1.807067] systemd[1]: Finished Virtual Console Setup.505machine # [ 2.180516] systemd[1]: Finished Coldplug All udev Devices.506machine # [ 2.182466] systemd[1]: Reached target System Initialization.507machine # [ 2.184458] systemd[1]: Reached target Basic System.508machine # [ 2.319833] (udev-worker)[108]: Network interface NamePolicy= disabled on kernel command line.509machine # [ 2.346975] (udev-worker)[106]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.510machine # [ 2.351239] (udev-worker)[106]: Network interface NamePolicy= disabled on kernel command line.511machine # [ 2.359015] systemd[1]: Found device /dev/disk/by-label/nixos.512machine # [ 2.361771] systemd[1]: Reached target Initrd Root Device.513machine # [ 2.363012] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...514machine # [ 2.406657] systemd-fsck[128]: nixos: clean, 12/524288 files, 58513/2097152 blocks515machine # [ 2.414680] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.516machine # [ 2.492364] systemd[1]: Mounting /sysroot...517machine # [ 2.522682] EXT4-fs (vda): mounted filesystem c8e45c96-dd61-4c49-9d15-3d10a493bf35 r/w with ordered data mode. Quota mode: none.518machine # [ 2.521556] systemd[1]: Mounted /sysroot.519machine # [ 2.523849] systemd[1]: Reached target Initrd Root File System.520machine # [ 2.531422] systemd[1]: Starting Mountpoints Configured in the Real Root...521machine # [ 2.551755] systemd-sysroot-fstab-check[136]: /sysroot should be mounted in the initrd, will request daemon-reload.522machine # [ 2.557056] systemd[1]: Reload requested from client PID 136 ('systemd-sysroot') (unit initrd-parse-etc.service)...523machine # [ 2.560295] systemd[1]: Reloading...524machine # [ 2.660174] systemd[1]: Reloading finished in 100 ms.525machine # [ 2.689869] systemd-sysroot-fstab-check[136]: Requesting initrd-fs.target/start/replace...526machine # [ 2.691140] systemd-sysroot-fstab-check[136]: Requesting swap.target/start/replace...527machine # [ 2.692912] systemd[1]: initrd-parse-etc.service: Deactivated successfully.528machine # [ 2.694363] systemd[1]: Finished Mountpoints Configured in the Real Root.529machine # [ 2.695424] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.530machine # [ 3.057000] fuse: init (API version 7.45)531machine # [ 3.082944] virtiofs virtio6: discovered new tag: nix-store532machine # [ 3.109096] (udev-worker)[103]: mtd0ro: Failed to find and pin callout binary "/nix/store/rzzrvlm7r31iq3im3h66nhxc2zh996l9-systemd-262/lib/udev/mtd_probe": No such file or directory533machine # [ 3.111661] (udev-worker)[103]: mtd0ro: /etc/udev/rules.d/75-probe_mtd.rules:5 IMPORT{program}="mtd_probe $devnode": Failed to execute "mtd_probe /dev/mtd0ro", ignoring: No such file or directory534machine # [ 3.130870] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.535machine # [ 3.132990] systemd[1]: Stopped Virtual Console Setup.536machine # [ 3.134066] systemd[1]: Stopping Virtual Console Setup...537machine # [ 3.138808] systemd[1]: Starting Virtual Console Setup...538machine # [ 3.143036] virtiofs virtio6: virtio_fs_setup_dax: No cache capability539machine # [ 3.158957] virtiofs virtio7: discovered new tag: shared540machine # [ 3.159803] virtiofs virtio7: virtio_fs_setup_dax: No cache capability541machine # [ 3.162223] virtiofs virtio8: discovered new tag: xchg542machine # [ 3.163082] virtiofs virtio8: virtio_fs_setup_dax: No cache capability543machine # [ 3.182470] systemd-vconsole-setup[156]: Configuration of first virtual console was skipped, ignoring remaining ones.544machine # [ 3.184471] systemd[1]: Finished Virtual Console Setup.545machine # [ 3.494144] systemd[1]: Mounting /sysroot/nix/.ro-store...546machine # [ 3.498180] systemd[1]: Mounting /sysroot/nix/.rw-store...547machine # [ 3.520164] systemd[1]: Mounting /sysroot/run...548machine # [ 3.525600] systemd[1]: Mounting /sysroot/tmp/shared...549machine # [ 3.541973] systemd[1]: Mounting /sysroot/tmp/xchg...550machine # [ 3.543851] systemd[1]: Mounted /sysroot/nix/.rw-store.551machine # [ 3.548169] systemd[1]: Mounted /sysroot/nix/.ro-store.552machine # [ 3.556596] systemd[1]: Starting rw-sysroot-nix-store.service...553machine # [ 3.567688] systemd[1]: Mounted /sysroot/run.554machine # [ 3.571168] systemd[1]: Mounted /sysroot/tmp/shared.555machine # [ 3.572369] systemd[1]: Mounted /sysroot/tmp/xchg.556machine # [ 3.577961] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.557machine # [ 3.579373] systemd[1]: Finished rw-sysroot-nix-store.service.558machine # [ 3.580756] systemd[1]: Mounting /sysroot/nix/store...559machine # [ 3.609219] systemd[1]: Mounted /sysroot/nix/store.560machine # [ 3.610379] systemd[1]: Reached target Initrd File Systems.561machine # [ 3.616110] systemd[1]: Starting Find NixOS closure...562machine # [ 3.617245] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...563machine # [ 3.644576] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.564machine # [ 3.658706] systemd[1]: Finished Find NixOS closure.565machine # [ 3.660864] systemd[1]: Reached target Initrd Default Target.566machine # [ 3.664444] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...567machine # [ 3.690929] systemd[1]: Stopped target Initrd Default Target.568machine # [ 3.692453] systemd[1]: Stopped target Basic System.569machine # [ 3.693808] systemd[1]: Stopped target Initrd Root Device.570machine # [ 3.695113] systemd[1]: Stopped target Path Units.571machine # [ 3.696433] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.572machine # [ 3.698149] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.573machine # [ 3.699905] systemd[1]: Stopped target Slice Units.574machine # [ 3.701122] systemd[1]: Stopped target Socket Units.575machine # [ 3.702266] systemd[1]: Stopped target System Initialization.576machine # [ 3.703649] systemd[1]: Stopped target Swaps.577machine # [ 3.704783] systemd[1]: Stopped target Timer Units.578machine # [ 3.706299] systemd[1]: dbus.socket: Deactivated successfully.579machine # [ 3.709432] systemd[1]: Closed D-Bus System Message Bus Socket.580machine # [ 3.713207] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.581machine # [ 3.716232] systemd[1]: Stopped Find NixOS closure.582machine # [ 3.719203] systemd[1]: Starting rw-sysroot-nix-store.service...583machine # [ 3.720639] systemd[1]: systemd-sysctl.service: Deactivated successfully.584machine # [ 3.722083] systemd[1]: Stopped Apply Kernel Variables.585machine # [ 3.723279] systemd[1]: systemd-modules-load.service: Deactivated successfully.586machine # [ 3.725117] systemd[1]: Stopped Load Kernel Modules.587machine # [ 3.727065] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.588machine # [ 3.730353] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.589machine # [ 3.731980] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.590machine # [ 3.733587] systemd[1]: Stopped Create System Files and Directories.591machine # [ 3.735298] systemd[1]: Stopped target Local File Systems.592machine # [ 3.736523] systemd[1]: Stopped target Preparation for Local File Systems.593machine # [ 3.737864] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.594machine # [ 3.739286] systemd[1]: Stopped Coldplug All udev Devices.595machine # [ 3.740467] systemd[1]: Stopping Rule-based Manager for Device Events and Files...596machine # [ 3.741948] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.597machine # [ 3.743450] systemd[1]: Stopped Virtual Console Setup.598machine # [ 3.744640] systemd[1]: initrd-cleanup.service: Deactivated successfully.599machine # [ 3.745969] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.600machine # [ 3.747368] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.601machine # [ 3.748992] systemd[1]: Finished rw-sysroot-nix-store.service.602machine # [ 3.750245] systemd[1]: systemd-udevd.service: Deactivated successfully.603machine # [ 3.751585] systemd[1]: Stopped Rule-based Manager for Device Events and Files.604machine # [ 3.753053] systemd[1]: systemd-udevd.service: Consumed 1.785s CPU time over 2.119s wall clock time, 31.6M memory peak.605machine # [ 3.754989] systemd[1]: systemd-udevd-varlink.socket: Deactivated successfully.606machine # [ 3.756330] systemd[1]: Closed udev Varlink Socket.607machine # [ 3.757266] systemd[1]: Starting Cleanup udev Database...608machine # [ 3.758266] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.609machine # [ 3.759672] systemd[1]: Stopped Create Static Device Nodes in /dev.610machine # [ 3.760837] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.611machine # [ 3.762247] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.612machine # [ 3.763480] systemd[1]: kmod-static-nodes.service: Deactivated successfully.613machine # [ 3.764709] systemd[1]: Stopped Create List of Static Device Nodes.614machine # [ 3.829626] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.615machine # [ 3.831091] systemd[1]: Finished Cleanup udev Database.616machine # [ 3.831970] systemd[1]: Reached target Switch Root.617machine # [ 3.833624] systemd[1]: Starting NixOS Activation...618machine # [ 3.947392] initrd-nixos-activation-start[195]: booting system configuration /nix/store/8k1872ywdrb70nlzgflp255y7vfdrij4-nixos-system-machine-test619machine # [ 3.984216] initrd-nixos-activation-start[195]: running activation script...620machine # [ 4.255832] initrd-nixos-activation-start[218]: setting up /etc...621machine # [ 4.384927] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.622machine # [ 4.386153] systemd[1]: Finished NixOS Activation.623machine # [ 4.387453] systemd[1]: Starting Switch Root...624machine # [ 4.425920] systemd[1]: Switching root.625machine # [ 4.536020] systemd-journald[79]: Received SIGTERM from PID 1 (systemd).626machine # [ 5.077695] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)627machine # [ 5.077756] systemd[1]: Detected virtualization qemu.628machine # [ 5.077810] systemd[1]: Detected architecture arm64.629machine # [ 5.077914] systemd[1]: Detected first boot.630machine # [ 5.081076] systemd[1]: Initializing machine ID from random generator.631machine # [ 5.231585] systemd[1]: bpf-restrict-fs: LSM BPF program attached632machine # [ 5.344939] systemd[1]: Applying preset policy.633machine # [ 5.565907] systemd[1]: Populated /etc with preset unit settings.634machine # [ 5.813020] systemd[1]: initrd-switch-root.service: Deactivated successfully.635machine # [ 5.814166] systemd[1]: Stopped initrd-switch-root.service.636machine # [ 5.816739] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.637machine # [ 5.820674] systemd[1]: Created slice Slice /system/getty.638machine # [ 5.823287] systemd[1]: Created slice User and Session Slice.639machine # [ 5.823974] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.640machine # [ 5.824617] systemd[1]: Started Forward Password Requests to Wall Directory Watch.641machine # [ 5.825200] systemd[1]: Expecting device /dev/hvc0...642machine # [ 5.825921] systemd[1]: Expecting device /dev/ttyAMA0...643machine # [ 5.826456] systemd[1]: Reached target Local Encrypted Volumes.644machine # [ 5.827092] systemd[1]: Stopped target initrd-fs.target.645machine # [ 5.827692] systemd[1]: Stopped target initrd-root-fs.target.646machine # [ 5.828326] systemd[1]: Stopped target initrd-switch-root.target.647machine # [ 5.828937] systemd[1]: Reached target Virtual Machines and Containers.648machine # [ 5.829540] systemd[1]: Reached target Path Units.649machine # [ 5.830123] systemd[1]: Reached target Remote File Systems.650machine # [ 5.830686] systemd[1]: Reached target Slice Units.651machine # [ 5.831277] systemd[1]: Reached target Swaps.652machine # [ 5.833233] systemd[1]: Listening on Query the User Interactively for a Password.653machine # [ 5.837111] systemd[1]: Listening on Process Core Dump Socket.654machine # [ 5.838648] systemd[1]: Listening on Credential Encryption/Decryption.655machine # [ 5.840154] systemd[1]: Listening on Factory Reset Management.656machine # [ 5.840715] systemd[1]: Listening on Hostname Service Socket.657machine # [ 5.845242] systemd[1]: Starting Journal Log Access Socket...658machine # [ 5.846249] systemd[1]: Listening on Journal Audit Socket.659machine # [ 5.848011] systemd[1]: Listening on Console Output Muting Service Socket.660machine # [ 5.848765] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.661machine # [ 5.849281] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os662machine # [ 5.849761] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki663machine # [ 5.853147] systemd[1]: Listening on Disk Repartitioning Service Socket.664machine # [ 5.853762] systemd[1]: Listening on udev Varlink Socket.665machine # [ 5.866681] systemd[1]: Mounting Huge Pages File System...666machine # [ 5.872412] systemd[1]: Mounting POSIX Message Queue File System...667machine # [ 5.881138] systemd[1]: Mounting Kernel Debug File System...668machine # [ 5.889982] systemd[1]: Mounting Kernel Trace File System...669machine # [ 5.903106] systemd[1]: Starting Create List of Static Device Nodes...670machine # [ 5.903732] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs671machine # [ 5.912281] systemd[1]: Mounting Kernel Configuration File System...672machine # [ 5.916016] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm673machine # [ 5.917832] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore674machine # [ 5.918225] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse675machine # [ 5.929619] systemd[1]: Mounting FUSE Control File System...676machine # [ 5.930022] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67677machine # [ 5.938507] systemd[1]: Starting Journal Service...678machine # [ 5.950396] systemd[1]: Starting Load Kernel Modules...679machine # [ 5.956471] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...680machine # [ 5.964414] systemd[1]: Starting Remount Root and Kernel File Systems...681machine # [ 5.964792] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os682machine # [ 5.977821] systemd[1]: Starting Coldplug All udev Devices...683machine # [ 5.980279] systemd[1]: Listening on Journal Log Access Socket.684machine # [ 5.980715] systemd[1]: Mounted Huge Pages File System.685machine # [ 5.981111] systemd[1]: Mounted POSIX Message Queue File System.686machine # [ 5.990487] systemd[1]: Mounted Kernel Debug File System.687machine # [ 5.990981] systemd[1]: Mounted Kernel Trace File System.688machine # [ 5.991438] systemd[1]: Mounted Kernel Configuration File System.689machine # [ 6.003929] systemd[1]: Mounted FUSE Control File System.690machine # [ 6.019690] systemd[1]: Finished Create List of Static Device Nodes.691machine # [ 6.023342] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...692machine # [ 6.044385] systemd-journald[289]: Collecting audit messages is enabled.693machine # [ 6.055431] systemd[1]: Queued start job for default target Multi-User System.694machine # [ 6.058154] systemd[1]: Started Journal Service.695machine # [ 6.061871] EXT4-fs (vda): re-mounted c8e45c96-dd61-4c49-9d15-3d10a493bf35.696machine # [ 6.060541] systemd[1]: systemd-journald.service: Deactivated successfully.697machine # [ 6.068668] systemd-oomd[291]: No swap; memory pressure usage will be degraded698machine # [ 6.072545] systemd-modules-load[290]: Using 2 probe threads699machine # [ 6.073599] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.700machine # [ 6.080326] systemd[1]: Finished Remount Root and Kernel File Systems.701machine # [ 6.081504] systemd[1]: Listening on Disk Image Download Service Socket.702machine # [ 6.082651] systemd[1]: Starting Flush Journal to Persistent Storage...703machine # [ 6.083786] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore704machine # [ 6.094581] systemd-modules-load[290]: Module 'atkbd' is built in705machine # [ 6.096523] systemd[1]: Starting Load/Save OS Random Seed...706machine # [ 6.099956] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os707machine # [ 6.106405] systemd-modules-load[290]: Module 'loop' is built in708machine # [ 6.110597] systemd[1]: Finished Load Kernel Modules.709machine # [ 6.115453] systemd[1]: Starting Apply Kernel Variables...710machine # [ 6.146422] systemd-journald[289]: Received client request to flush runtime journal.711machine # [ 6.186926] systemd[1]: Finished Load/Save OS Random Seed.712machine # [ 6.188855] systemd[1]: Reached target First Boot Complete.713machine # [ 6.189780] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.714machine # [ 6.190874] systemd[1]: Starting Create Static Device Nodes in /dev...715machine # [ 6.191854] systemd[1]: Finished Apply Kernel Variables.716machine # [ 6.197189] systemd[1]: Finished Flush Journal to Persistent Storage.717machine # [ 6.225280] systemd[1]: Finished Create Static Device Nodes in /dev.718machine # [ 6.226418] systemd[1]: Reached target Preparation for Local File Systems.719machine # [ 6.228396] systemd[1]: Starting Rule-based Manager for Device Events and Files...720machine # [ 6.275530] systemd-udevd[318]: Using default interface naming scheme 'v261'.721machine # [ 6.306661] systemd[1]: Started Rule-based Manager for Device Events and Files.722machine # [ 6.670216] systemd[1]: Finished Coldplug All udev Devices.723machine # [ 6.725860] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs724machine # [ 6.741862] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse725machine # [ 6.810348] systemd[1]: Mounting /run/wrappers...726machine # [ 6.820457] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.727machine # [ 6.826087] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.728machine # [ 6.851326] systemd[1]: Mounted /run/wrappers.729machine # [ 6.853130] systemd[1]: Reached target Local File Systems.730machine # [ 6.855622] systemd[1]: Listening on Boot Loader Control Service Socket.731machine # [ 6.857878] systemd[1]: Starting register-nix-paths.service...732machine # [ 6.860138] systemd[1]: Starting Create SUID/SGID Wrappers...733machine # [ 6.864599] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.734machine # [ 6.869558] systemd[1]: Starting Save Transient machine-id to Disk...735machine # [ 6.876003] systemd[1]: Starting Create System Files and Directories...736machine # [ 6.942681] (udev-worker)[340]: Network interface NamePolicy= disabled on kernel command line.737machine # [ 6.965756] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.738machine # [ 6.968324] systemd[1]: Finished Save Transient machine-id to Disk.739machine # [ 6.975096] systemd[1]: Finished Create System Files and Directories.740machine # [ 6.985910] systemd[1]: Starting Rebuild Journal Catalog...741machine # [ 6.992735] systemd[1]: Starting Record System Boot/Shutdown in UTMP...742machine # [ 7.053159] systemd[1]: Finished Record System Boot/Shutdown in UTMP.743machine # [ 7.078932] systemd[1]: Finished Rebuild Journal Catalog.744machine # [ 7.081599] systemd[1]: Starting Update is Completed...745machine # [ 7.095108] (udev-worker)[324]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.746machine # [ 7.098603] (udev-worker)[324]: Network interface NamePolicy= disabled on kernel command line.747machine # [ 7.134128] systemd[1]: Finished Update is Completed.748machine # [ 7.267509] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.749machine # [ 7.269301] systemd[1]: Finished Create SUID/SGID Wrappers.750machine # [ 7.279615] systemd[1]: Condition check resulted in Virtio network device being skipped.751machine # [ 7.282491] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore752machine # [ 7.288548] systemd[1]: Starting Create SUID/SGID Wrappers...753machine # [ 7.289622] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.754machine # [ 7.290952] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67755machine # [ 7.295259] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore756machine # [ 7.298227] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os757machine # [ 7.300744] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os758machine # [ 7.334664] mousedev: PS/2 mouse device common for all mice759machine # [ 7.341950] systemd[1]: Finished register-nix-paths.service.760machine # [ 7.548568] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.761machine # [ 7.552329] systemd[1]: Finished Create SUID/SGID Wrappers.762machine # [ 7.554677] systemd[1]: Reached target System Initialization.763machine # [ 7.558235] systemd[1]: Started Discard unused filesystem blocks once a week.764machine # [ 7.559427] systemd[1]: Started Daily Cleanup of Temporary Directories.765machine # [ 7.561055] systemd[1]: Reached target Timer Units.766machine # [ 7.567243] systemd[1]: Listening on D-Bus System Message Bus Socket.767machine # [ 7.569148] systemd[1]: Listening on Nix Daemon Socket.768machine # [ 7.572763] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.769machine # [ 7.580286] systemd[1]: Reached target Socket Units.770machine # [ 7.581174] systemd[1]: Reached target Basic System.771machine # [ 7.583969] systemd[1]: Started backdoor.service.772machine # [ 7.584890] systemd[1]: Starting Import lastlog data into lastlog2 database...773machine # [ 7.586603] systemd[1]: Starting Name Service Cache Daemon (nsncd)...774machine # [ 7.587753] systemd[1]: Starting Post-Boot Actions...775machine # [ 7.592288] systemd[1]: Started Reset console on configuration changes.776machine # [ 7.599385] systemd[1]: Starting resolvconf update...777machine # [ 7.604569] systemd[1]: Starting D-Bus System Message Bus...778machine # [ 7.651629] systemd[1]: Finished Post-Boot Actions.779machine # [ 7.673099] systemd[1]: Started Name Service Cache Daemon (nsncd).780machine # [ 7.675541] nsncd[481]: Nov 12 17:02:34.350 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"781machine # connecting to host...782machine # [ 7.691018] systemd[1]: Reached target Host and Network Name Lookups.783machine # [ 7.695517] systemd[1]: Reached target User and Group Name Lookups.784machine # [ 7.697422] systemd[1]: Starting User Login Management...785[8.48s] machine: Guest shell says: b'Spawning backdoor root shell...\n'786machine # [ 7.738818] dbus-broker-launch[485]: Looking up NSS user entry for 'systemd-timesync'...787[8.49s] machine: connected to guest root shell788[8.49s] machine: (connecting took 8.06 seconds)789[8.49s] machine: (finished: waiting for the VM to finish booting, in 8.49 seconds)790machine # [ 7.746512] dbus-broker-launch[485]: NSS returned no entry for 'systemd-timesync'791machine # [ 7.752161] dbus-broker-launch[485]: Invalid user-name in /nix/store/zwpdq5dl6mgp5cnkswh4wmrmps0m71lm-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"792machine # [ 7.762980] systemd[1]: Finished Import lastlog data into lastlog2 database.793machine # [ 7.766383] systemd[1]: Started D-Bus System Message Bus.794machine # [ 7.813000] dbus-broker-launch[485]: Ready795machine # [ 7.827559] systemd-logind[504]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)796machine # [ 7.836391] systemd-logind[504]: Watching system buttons on /dev/input/event0 (gpio-keys)797machine # [ 7.837603] systemd-logind[504]: New seat seat0.798machine # [ 7.838334] systemd[1]: Started User Login Management.799machine # [ 7.852270] systemd[1]: Starting linger-users.service...800machine # [ 7.895524] systemd[1]: Stopped target Host and Network Name Lookups.801machine # [ 7.896682] systemd[1]: Stopping Host and Network Name Lookups...802machine # [ 7.897639] systemd[1]: Stopped target User and Group Name Lookups.803machine # [ 7.901587] systemd[1]: Stopping User and Group Name Lookups...804machine # [ 7.904884] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...805machine # [ 7.905871] systemd[1]: linger-users.service: Deactivated successfully.806machine # [ 7.912505] systemd[1]: Finished linger-users.service.807machine # [ 7.913372] systemd[1]: nscd.service: Deactivated successfully.808machine # [ 7.914212] systemd[1]: Stopped Name Service Cache Daemon (nsncd).809machine # [ 7.915119] systemd[1]: Starting Name Service Cache Daemon (nsncd)...810machine # [ 7.967691] nsncd[564]: Nov 12 17:02:34.646 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"811machine # [ 7.972557] systemd[1]: Started Name Service Cache Daemon (nsncd).812machine # [ 7.976179] systemd[1]: Reached target Host and Network Name Lookups.813machine # [ 7.977149] systemd[1]: Reached target User and Group Name Lookups.814machine # [ 7.987542] systemd[1]: Finished resolvconf update.815machine # [ 7.991606] systemd[1]: Reached target Preparation for Network.816machine # [ 7.996383] systemd[1]: Starting DHCP Client...817machine # [ 7.997111] systemd[1]: Starting Address configuration of eth1...818machine # [ 8.002318] systemd[1]: Starting Extra networking commands....819machine # [ 8.096943] network-addresses-eth1-start[590]: adding address 192.168.1.1/24... done820machine # [ 8.106144] network-addresses-eth1-start[590]: adding address 2001:db8:1::1/64... done821machine # [ 8.132533] systemd[1]: Finished Address configuration of eth1.822machine # [ 8.167790] dhcpcd[596]: dhcpcd-10.3.2 starting823machine # [ 8.173934] dhcpcd[638]: dev: loaded udev824machine # [ 8.202109] 8021q: 802.1Q VLAN Support v1.8825machine # [ 8.202470] 8021q: adding VLAN 0 to HW filter on device eth1826machine # [ 8.223580] systemd[1]: Finished Extra networking commands..827machine # [ 8.227445] systemd[1]: Reached target Network.828machine # [ 8.247875] systemd[1]: Starting PostgreSQL Server...829machine # [ 8.283549] systemd[1]: Started RustFS S3-compatible object storage.830machine # [ 8.299957] systemd[1]: Starting Setup RustFS bucket...831machine # [ 8.309815] systemd[1]: Starting Permit User Sessions...832machine # [ 8.357928] cfg80211: Loading compiled-in X.509 certificates for regulatory database833machine # [ 8.358762] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'834machine # [ 8.359203] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'835machine # [ 8.361127] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2836machine # [ 8.361526] cfg80211: failed to load regulatory.db837machine # [ 8.399747] systemd[1]: Finished Permit User Sessions.838machine # [ 8.408179] systemd[1]: Started Getty on tty1.839machine # [ 8.409040] systemd[1]: Reached target Login Prompts.840machine # [ 8.483318] dhcpcd[638]: eth0: waiting for carrier[ 8.486045] 8021q: adding VLAN 0 to HW filter on device eth0841machine # 842machine # [ 8.485327] dhcpcd[638]: eth0: carrier acquired843machine # [ 8.504107] dhcpcd[638]: DUID 00:01:00:01:32:88:ad:ab:52:54:00:12:34:56844machine # [ 8.505248] dhcpcd[638]: eth0: IAID 00:12:34:56845machine # [ 8.505945] dhcpcd[638]: eth0: adding address fe80::5054:ff:fe12:3456846machine # [ 8.684700] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input3847machine # [ 8.724108] postgresql-pre-start[688]: The files belonging to this database system will be owned by user "postgres".848machine # [ 8.725691] postgresql-pre-start[688]: This user must also own the server process.849machine # [ 8.726837] postgresql-pre-start[688]: The database cluster will be initialized with locale "en_US.UTF-8".850machine # [ 8.736203] postgresql-pre-start[688]: The default database encoding has accordingly been set to "UTF8".851machine # [ 8.737563] postgresql-pre-start[688]: The default text search configuration will be set to "english".852machine # [ 8.738869] postgresql-pre-start[688]: Data page checksums are enabled.853machine # [ 8.739800] postgresql-pre-start[688]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok854machine # [ 8.741312] postgresql-pre-start[688]: creating subdirectories ... ok855machine # [ 8.742217] postgresql-pre-start[688]: selecting dynamic shared memory implementation ... posix856machine # [ 8.852672] postgresql-pre-start[688]: selecting default "max_connections" ... 100857machine # [ 8.917695] systemd[1]: Starting Virtual Console Setup...858machine # [ 8.951947] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.859machine # [ 8.965596] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.860machine # [ 8.966849] systemd[1]: Stopped Virtual Console Setup.861machine # [ 8.972951] systemd[1]: Starting Virtual Console Setup...862machine # [ 9.022660] systemd-logind[504]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)863machine # [ 9.039009] postgresql-pre-start[688]: selecting default "shared_buffers" ... 128MB864machine # [ 9.122069] dhcpcd[638]: eth0: soliciting a DHCP lease865machine # [ 9.132461] dhcpcd[638]: eth0: offered 10.0.2.15 from 10.0.2.2866machine # [ 9.148303] dhcpcd[638]: eth0: probing address 10.0.2.15/24867machine # [ 9.192564] systemd-vconsole-setup[718]: Configuration of first virtual console was skipped, ignoring remaining ones.868machine # [ 9.200353] systemd[1]: Finished Virtual Console Setup.869machine # [ 9.691289] postgresql-pre-start[688]: selecting default time zone ... UTC870machine # [ 9.693324] postgresql-pre-start[688]: creating configuration files ... ok871machine # [ 9.961517] postgresql-pre-start[688]: running bootstrap script ... ok872machine # [ 10.522166] postgresql-pre-start[688]: performing post-bootstrap initialization ... ok873machine # [ 10.657739] postgresql-pre-start[688]: syncing data to disk ... ok874machine # [ 10.659073] postgresql-pre-start[688]: initdb: warning: enabling "trust" authentication for local connections875machine # [ 10.660987] postgresql-pre-start[688]: 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.876machine # [ 10.663901] postgresql-pre-start[688]: Success. You can now start the database server using:877machine # [ 10.665595] postgresql-pre-start[688]: pg_ctl -D /var/lib/postgresql/18 -l logfile start878machine # [ 10.892426] postgres[745]: [745] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit879machine # [ 10.896447] postgres[745]: [745] LOG: listening on IPv4 address "0.0.0.0", port 5432880machine # [ 10.898654] postgres[745]: [745] LOG: listening on IPv6 address "::", port 5432881machine # [ 10.900579] postgres[745]: [745] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"882machine # [ 10.910911] postgres[754]: [754] LOG: database system was shut down at 2026-11-12 17:02:37 GMT883machine # [ 10.920766] postgres[745]: [745] LOG: database system is ready to accept connections884machine # [ 10.923738] systemd[1]: Started PostgreSQL Server.885machine # [ 10.930149] systemd[1]: Starting PostgreSQL Setup Scripts...886machine # [ 11.180757] postgresql-setup-start[765]: CREATE DATABASE887machine # [ 11.232905] postgresql-setup-start[779]: CREATE ROLE888machine # [ 11.253817] postgresql-setup-start[781]: ALTER DATABASE889machine # [ 11.260241] systemd[1]: Finished PostgreSQL Setup Scripts.890machine # [ 11.261555] systemd[1]: Reached target PostgreSQL.891machine # [ 11.296847] dhcpcd[638]: eth0: soliciting an IPv6 router892machine # [ 11.298261] dhcpcd[638]: eth0: Router Advertisement from fe80::2893machine # [ 11.299746] dhcpcd[638]: eth0: adding address fec0::5054:ff:fe12:3456/64894machine # [ 11.301349] dhcpcd[638]: eth0: adding route to fec0::/64895machine # [ 11.302541] dhcpcd[638]: eth0: adding default route via fe80::2896machine # [ 14.290793] dhcpcd[638]: eth0: leased 10.0.2.15 for 86400 seconds897machine # [ 14.291083] dhcpcd[638]: eth0: adding route to 10.0.2.0/24898machine # [ 14.291198] dhcpcd[638]: eth0: adding default route via 10.0.2.2899machine # [ 14.449999] systemd[1]: Started DHCP Client.900machine # [ 14.451544] systemd[1]: Reached target Network is Online.901machine # [ 14.456898] systemd[1]: Starting k3s service...902machine # [ 14.520140] k3s[872]: time="2026-11-12T17:02:41Z" level=info msg="Acquiring lock file /var/lib/rancher/k3s/data/.lock"903machine # [ 14.522728] k3s[872]: time="2026-11-12T17:02:41Z" level=info msg="Preparing data dir /var/lib/rancher/k3s/data/b9f7776539d53e1567b480015e2ee0c0a8aa3ac6b7b20aaae82735601aa59b06"904machine # [ 16.093793] rustfs-setup-start[889]: mb s3://niks3905machine # [ 16.105741] systemd[1]: Finished Setup RustFS bucket.906machine # [ 17.602261] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Starting k3s 1.36.5+k3s1 (3dd98cc5)"907machine # [ 17.610502] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdle=20, maxOpen=0, maxLifetime=0s, maxIdleTime=2m0s"908machine # [ 17.613131] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Kine built with sqlite from github.com/mattn/go-sqlite3 version 3.53.3"909machine # [ 17.615293] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Configuring database table schema and indexes, this may take a moment..."910machine # [ 17.619627] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Database tables and indexes are up to date"911machine # [ 17.622106] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Running startup VACUUM to reclaim disk space, this may take a moment..."912machine # [ 17.626458] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Startup VACUUM completed successfully"913machine # [ 17.628865] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Kine available at unix://kine.sock"914machine # [ 17.630910] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"915machine # [ 17.634864] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="Datastore connection validated successfully, proceeding with bootstrap data generation"916machine # [ 17.637860] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="generated self-signed CA certificate CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:44.31596942 +0000 UTC notAfter=2036-11-09 16:02:44.31596942 +0000 UTC"917machine # [ 17.642204] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"918machine # [ 17.646314] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"919machine # [ 17.650370] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"920machine # [ 17.654162] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"921machine # [ 17.657648] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"922machine # [ 17.661127] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"923machine # [ 17.664391] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="generated self-signed CA certificate CN=k3s-server-ca@1794502964: notBefore=2026-11-12 16:02:44.3201883 +0000 UTC notAfter=2036-11-09 16:02:44.3201883 +0000 UTC"924machine # [ 17.667563] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-server-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"925machine # [ 17.670602] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=kube-scheduler signed by CN=k3s-server-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"926machine # [ 17.673511] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=kube-controller-manager signed by CN=k3s-server-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"927machine # [ 17.676773] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="generated self-signed CA certificate CN=k3s-request-header-ca@1794502964: notBefore=2026-11-12 16:02:44.3222854 +0000 UTC notAfter=2036-11-09 16:02:44.3222854 +0000 UTC"928machine # [ 17.679873] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"929machine # [ 17.683023] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="generated self-signed CA certificate CN=etcd-server-ca@1794502964: notBefore=2026-11-12 16:02:44.32310682 +0000 UTC notAfter=2036-11-09 16:02:44.32310682 +0000 UTC"930machine # [ 17.686174] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"931machine # [ 17.689056] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="generated self-signed CA certificate CN=etcd-peer-ca@1794502964: notBefore=2026-11-12 16:02:44.32389676 +0000 UTC notAfter=2036-11-09 16:02:44.32389676 +0000 UTC"932machine # [ 17.692035] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"933machine # [ 17.694803] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"934machine # [ 17.697787] k3s[872]: time="2026-11-12T17:02:44Z" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1794502964: notBefore=2026-11-12 16:02:44 +0000 UTC notAfter=2027-11-12 16:02:44 +0000 UTC"935machine # [ 17.700588] k3s[872]: time="2026-11-12T17:02:44Z" level=warning msg="dynamiclistener [::]:6443: no cached certificate available for preload - deferring certificate load until storage initialization or first client request"936machine # [ 17.703462] k3s[872]: time="2026-11-12T17:02:44Z" 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__e927_9041_2fbc_de71-7f5ffa:fec0::e927:9041:2fbc:de71 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=0F6948538D22A7AE504108EA0B738CE1EE8B28BC]"937machine # [ 19.015103] k3s[872]: time="2026-11-12T17:02:45Z" level=info msg="Password verified locally for node machine"938machine # [ 19.017696] k3s[872]: time="2026-11-12T17:02:45Z" level=info msg="certificate CN=machine signed by CN=k3s-server-ca@1794502964: notBefore=2026-11-12 16:02:45 +0000 UTC notAfter=2027-11-12 16:02:45 +0000 UTC"939machine # [ 19.428994] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="certificate CN=system:node:machine,O=system:nodes signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:46 +0000 UTC notAfter=2027-11-12 16:02:46 +0000 UTC"940machine # [ 19.551755] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:46 +0000 UTC notAfter=2027-11-12 16:02:46 +0000 UTC"941machine # [ 19.704370] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1794502964: notBefore=2026-11-12 16:02:46 +0000 UTC notAfter=2027-11-12 16:02:46 +0000 UTC"942machine # [ 19.837762] k3s[872]: time="2026-11-12T17:02:46Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:45340: runtime core not ready"943machine # [ 19.964941] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Module overlay was already loaded"944machine # [ 20.027478] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.945machine # [ 20.033069] Bridge firewalling registered946machine # [ 20.037051] k3s[872]: time="2026-11-12T17:02:46Z" level=warning msg="Failed to load kernel module iptable_nat with modprobe"947machine # [ 20.042791] k3s[872]: time="2026-11-12T17:02:46Z" level=warning msg="Failed to load kernel module iptable_filter with modprobe"948machine # [ 20.051489] k3s[872]: time="2026-11-12T17:02:46Z" level=warning msg="Failed to load kernel module nft-expr-counter with modprobe"949machine # [ 20.103304] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Set sysctl 'net/ipv4/conf/default/forwarding' to 1"950machine # [ 20.106575] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 131072"951machine # [ 20.109330] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400"952machine # [ 20.112488] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600"953machine # [ 20.115303] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Set sysctl 'net/ipv4/conf/all/forwarding' to 1"954machine # [ 20.117659] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Creating k3s-cert-monitor event broadcaster"955machine # [ 20.119910] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"956machine # [ 20.122367] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Saving cluster bootstrap data to datastore"957machine # [ 20.124400] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"958machine # [ 20.126863] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Connection to etcd is ready"959machine # [ 20.128612] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="ETCD server is now running"960machine # [ 20.131556] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Polling for API server readiness: GET /readyz failed: the server is currently unable to handle the request"961machine # [ 20.134510] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Handling backend connection request [machine]"962machine # [ 20.136436] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"963machine # [ 20.138455] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"964machine # [ 20.140779] k3s[872]: time="2026-11-12T17:02:46Z" 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 # [ 20.168793] k3s[872]: time="2026-11-12T17:02:46Z" 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 # [ 20.175765] k3s[872]: time="2026-11-12T17:02:46Z" 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 # [ 20.198631] k3s[872]: time="2026-11-12T17:02:46Z" 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 # [ 20.209436] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Server node token is available at /var/lib/rancher/k3s/server/token"969machine # [ 20.211259] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="To join server node to cluster: k3s server -s https://10.0.2.15:6443 -t ${SERVER_NODE_TOKEN}"970machine # [ 20.213344] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Agent node token is available at /var/lib/rancher/k3s/server/agent-token"971machine # [ 20.215216] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="To join agent node to cluster: k3s agent -s https://10.0.2.15:6443 -t ${AGENT_NODE_TOKEN}"972machine # [ 20.217273] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log"973machine # [ 20.219128] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml"974machine # [ 20.221076] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"975machine # [ 20.222547] k3s[872]: time="2026-11-12T17:02:46Z" level=info msg="Run: k3s kubectl"976machine # [ 20.223707] k3s[872]: I1112 17:02:46.826438 872 options.go:263] external host was not specified, using 10.0.2.15977machine # [ 20.225309] k3s[872]: I1112 17:02:46.829708 872 server.go:158] Version: v1.36.5+k3s1978machine # [ 20.226538] k3s[872]: I1112 17:02:46.829752 872 server.go:160] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""979machine # [ 20.303091] k3s[872]: time="2026-11-12T17:02:46Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:45384: runtime core not ready"980machine # [ 20.376105] k3s[872]: E1112 17:02:47.055449 872 options.go:205] The manifest file is empty, ignoring.981machine # [ 20.377662] k3s[872]: I1112 17:02:47.055848 872 shared_informer.go:381] "Waiting for caches to sync" controller="node_authorizer"982machine # [ 20.394554] k3s[872]: I1112 17:02:47.075112 872 shared_informer.go:402] "Waiting for caches to sync"983machine # [ 20.400153] k3s[872]: I1112 17:02:47.075454 872 shared_informer.go:402] "Waiting for caches to sync"984machine # [ 20.401619] k3s[872]: I1112 17:02:47.078533 872 plugins.go:157] Loaded 15 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,PodGroupProtection,RuntimeClass,DefaultIngressClass,PodTopologyLabels,MutatingAdmissionPolicy,MutatingAdmissionWebhook.985machine # [ 20.406687] k3s[872]: I1112 17:02:47.078565 872 plugins.go:160] Loaded 17 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,ClusterTrustBundleAttest,CertificateSubjectRestriction,PodGroupWorkloadExists,NodeDeclaredFeatureValidator,JobValidation,PodResizeValidator,ValidatingAdmissionPolicy,ValidatingAdmissionWebhook,ResourceQuota.986machine # [ 20.416200] k3s[872]: I1112 17:02:47.079081 872 instance.go:240] Using reconciler: lease987machine # [ 20.417497] k3s[872]: I1112 17:02:47.092108 872 handler.go:304] Adding GroupVersion apiextensions.k8s.io v1 to ResourceManager988machine # [ 20.419089] k3s[872]: W1112 17:02:47.092139 872 genericapiserver.go:798] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.989machine # [ 20.421041] k3s[872]: I1112 17:02:47.101664 872 cidrallocator.go:198] starting ServiceCIDR Allocator Controller990machine # [ 20.463487] k3s[872]: time="2026-11-12T17:02:47Z" 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 # [ 20.510490] k3s[872]: I1112 17:02:47.191057 872 handler.go:304] Adding GroupVersion v1 to ResourceManager992machine # [ 20.512200] k3s[872]: I1112 17:02:47.191475 872 apis.go:112] API group "internal.apiserver.k8s.io" is not enabled, skipping.993machine # [ 20.546643] k3s[872]: I1112 17:02:47.227231 872 apis.go:112] API group "storagemigration.k8s.io" is not enabled, skipping.994machine # [ 20.583976] k3s[872]: I1112 17:02:47.264468 872 handler.go:304] Adding GroupVersion authentication.k8s.io v1 to ResourceManager995machine # [ 20.587546] k3s[872]: W1112 17:02:47.267943 872 genericapiserver.go:798] Skipping API authentication.k8s.io/v1beta1 because it has no resources.996machine # [ 20.589665] k3s[872]: W1112 17:02:47.267996 872 genericapiserver.go:798] Skipping API authentication.k8s.io/v1alpha1 because it has no resources.997machine # [ 20.591513] k3s[872]: I1112 17:02:47.270149 872 handler.go:304] Adding GroupVersion authorization.k8s.io v1 to ResourceManager998machine # [ 20.593628] k3s[872]: W1112 17:02:47.270930 872 genericapiserver.go:798] Skipping API authorization.k8s.io/v1beta1 because it has no resources.999machine # [ 20.596784] k3s[872]: I1112 17:02:47.275922 872 handler.go:304] Adding GroupVersion autoscaling v2 to ResourceManager1000machine # [ 20.613478] k3s[872]: I1112 17:02:47.294021 872 handler.go:304] Adding GroupVersion autoscaling v1 to ResourceManager1001machine # [ 20.618869] k3s[872]: I1112 17:02:47.299405 872 handler.go:304] Adding GroupVersion batch v1 to ResourceManager1002machine # [ 20.621715] k3s[872]: W1112 17:02:47.299437 872 genericapiserver.go:798] Skipping API batch/v1beta1 because it has no resources.1003machine # [ 20.624982] k3s[872]: I1112 17:02:47.300980 872 handler.go:304] Adding GroupVersion certificates.k8s.io v1 to ResourceManager1004machine # [ 20.626557] k3s[872]: W1112 17:02:47.301000 872 genericapiserver.go:798] Skipping API certificates.k8s.io/v1beta1 because it has no resources.1005machine # [ 20.632151] k3s[872]: W1112 17:02:47.301008 872 genericapiserver.go:798] Skipping API certificates.k8s.io/v1alpha1 because it has no resources.1006machine # [ 20.633973] k3s[872]: I1112 17:02:47.302985 872 handler.go:304] Adding GroupVersion coordination.k8s.io v1 to ResourceManager1007machine # [ 20.635543] k3s[872]: W1112 17:02:47.303006 872 genericapiserver.go:798] Skipping API coordination.k8s.io/v1beta1 because it has no resources.1008machine # [ 20.639931] k3s[872]: W1112 17:02:47.303016 872 genericapiserver.go:798] Skipping API coordination.k8s.io/v1alpha2 because it has no resources.1009machine # [ 20.641874] k3s[872]: I1112 17:02:47.303999 872 handler.go:304] Adding GroupVersion discovery.k8s.io v1 to ResourceManager1010machine # [ 20.643402] k3s[872]: W1112 17:02:47.304016 872 genericapiserver.go:798] Skipping API discovery.k8s.io/v1beta1 because it has no resources.1011machine # [ 20.648171] k3s[872]: I1112 17:02:47.310104 872 handler.go:304] Adding GroupVersion networking.k8s.io v1 to ResourceManager1012machine # [ 20.649748] k3s[872]: W1112 17:02:47.310134 872 genericapiserver.go:798] Skipping API networking.k8s.io/v1beta1 because it has no resources.1013machine # [ 20.651482] k3s[872]: I1112 17:02:47.311341 872 handler.go:304] Adding GroupVersion node.k8s.io v1 to ResourceManager1014machine # [ 20.653051] k3s[872]: W1112 17:02:47.311362 872 genericapiserver.go:798] Skipping API node.k8s.io/v1beta1 because it has no resources.1015machine # [ 20.654804] k3s[872]: W1112 17:02:47.311369 872 genericapiserver.go:798] Skipping API node.k8s.io/v1alpha1 because it has no resources.1016machine # [ 20.658916] k3s[872]: I1112 17:02:47.318717 872 handler.go:304] Adding GroupVersion policy v1 to ResourceManager1017machine # [ 20.660401] k3s[872]: W1112 17:02:47.318751 872 genericapiserver.go:798] Skipping API policy/v1beta1 because it has no resources.1018machine # [ 20.662001] k3s[872]: I1112 17:02:47.329347 872 handler.go:304] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager1019machine # [ 20.663671] k3s[872]: W1112 17:02:47.329377 872 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.1020machine # [ 20.665610] k3s[872]: W1112 17:02:47.329391 872 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.1021machine # [ 20.667564] k3s[872]: I1112 17:02:47.330314 872 handler.go:304] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager1022machine # [ 20.669258] k3s[872]: W1112 17:02:47.330328 872 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.1023machine # [ 20.671090] k3s[872]: W1112 17:02:47.330336 872 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1alpha2 because it has no resources.1024machine # [ 20.672992] k3s[872]: I1112 17:02:47.349282 872 handler.go:304] Adding GroupVersion storage.k8s.io v1 to ResourceManager1025machine # [ 20.674547] k3s[872]: W1112 17:02:47.349348 872 genericapiserver.go:798] Skipping API storage.k8s.io/v1beta1 because it has no resources.1026machine # [ 20.676330] k3s[872]: W1112 17:02:47.349359 872 genericapiserver.go:798] Skipping API storage.k8s.io/v1alpha1 because it has no resources.1027machine # [ 20.678166] k3s[872]: I1112 17:02:47.354237 872 handler.go:304] Adding GroupVersion flowcontrol.apiserver.k8s.io v1 to ResourceManager1028machine # [ 20.679850] k3s[872]: W1112 17:02:47.354273 872 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta3 because it has no resources.1029machine # [ 20.681929] k3s[872]: W1112 17:02:47.356759 872 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta2 because it has no resources.1030machine # [ 20.683740] k3s[872]: W1112 17:02:47.356767 872 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta1 because it has no resources.1031machine # [ 20.692273] k3s[872]: I1112 17:02:47.369717 872 handler.go:304] Adding GroupVersion apps v1 to ResourceManager1032machine # [ 20.693811] k3s[872]: W1112 17:02:47.369765 872 genericapiserver.go:798] Skipping API apps/v1beta2 because it has no resources.1033machine # [ 20.695481] k3s[872]: W1112 17:02:47.369775 872 genericapiserver.go:798] Skipping API apps/v1beta1 because it has no resources.1034machine # [ 20.699783] k3s[872]: I1112 17:02:47.380215 872 handler.go:304] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager1035machine # [ 20.702404] k3s[872]: W1112 17:02:47.380932 872 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.1036machine # [ 20.704604] k3s[872]: W1112 17:02:47.380967 872 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources.1037machine # [ 20.706687] k3s[872]: I1112 17:02:47.381915 872 handler.go:304] Adding GroupVersion events.k8s.io v1 to ResourceManager1038machine # [ 20.712182] k3s[872]: W1112 17:02:47.381934 872 genericapiserver.go:798] Skipping API events.k8s.io/v1beta1 because it has no resources.1039machine # [ 20.714771] k3s[872]: I1112 17:02:47.389945 872 handler.go:304] Adding GroupVersion resource.k8s.io v1 to ResourceManager1040machine # [ 20.716817] k3s[872]: W1112 17:02:47.389985 872 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta2 because it has no resources.1041machine # [ 20.719454] k3s[872]: W1112 17:02:47.389996 872 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta1 because it has no resources.1042machine # [ 20.721504] k3s[872]: W1112 17:02:47.390002 872 genericapiserver.go:798] Skipping API resource.k8s.io/v1alpha3 because it has no resources.1043machine # [ 20.724114] k3s[872]: I1112 17:02:47.404726 872 handler.go:304] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager1044machine # [ 20.727449] k3s[872]: W1112 17:02:47.406512 872 genericapiserver.go:798] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.1045machine # [ 21.291569] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="containerd is now running"1046machine # [ 21.293085] k3s[872]: I1112 17:02:47.972430 872 secure_serving.go:214] Serving securely on 127.0.0.1:64441047machine # [ 21.296204] k3s[872]: I1112 17:02:47.972505 872 tlsconfig.go:243] "Starting DynamicServingCertificateController"1048machine # [ 21.297847] k3s[872]: I1112 17:02:47.975192 872 local_available_controller.go:156] Starting LocalAvailability controller1049machine # [ 21.299450] k3s[872]: I1112 17:02:47.975237 872 cache.go:32] Waiting for caches to sync for LocalAvailability controller1050machine # [ 21.303953] k3s[872]: I1112 17:02:47.975861 872 controller.go:113] "Deleting old lease on startup" lease="kube-system/apiserver-ik4pcwfs7qgdl76byc4pomgvia"1051machine # [ 21.306167] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="Starting legacy_token_tracking_controller" logger=k3s1052machine # [ 21.307631] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="Waiting for caches to sync" logger=k3s1053machine # [ 21.312150] k3s[872]: I1112 17:02:47.976489 872 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"1054machine # [ 21.315032] k3s[872]: I1112 17:02:47.976517 872 controller.go:87] "Starting OpenAPI AggregationController"1055machine # [ 21.320184] k3s[872]: I1112 17:02:47.977120 872 apiservice_controller.go:100] Starting APIServiceRegistrationController1056machine # [ 21.321724] k3s[872]: I1112 17:02:47.977143 872 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller1057machine # [ 21.323394] k3s[872]: I1112 17:02:47.977175 872 controller.go:89] "Starting OpenAPI V3 AggregationController"1058machine # [ 21.324922] k3s[872]: I1112 17:02:47.972575 872 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1059machine # [ 21.327089] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg=Starting controller=kubernetes-service-cidr-controller logger=k3s1060machine # [ 21.328705] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="Waiting for caches to sync" logger=k3s1061machine # [ 21.330021] k3s[872]: I1112 17:02:47.982056 872 customresource_discovery_controller.go:294] Starting DiscoveryController1062machine # [ 21.331507] k3s[872]: I1112 17:02:47.982164 872 system_namespaces_controller.go:66] Starting system namespaces controller1063machine # [ 21.336129] k3s[872]: I1112 17:02:47.982196 872 remote_available_controller.go:434] Starting RemoteAvailability controller1064machine # [ 21.337673] k3s[872]: I1112 17:02:47.982206 872 cache.go:32] Waiting for caches to sync for RemoteAvailability controller1065machine # [ 21.343216] k3s[872]: I1112 17:02:47.982237 872 aggregator.go:185] waiting for initial CRD sync...1066machine # [ 21.344570] k3s[872]: I1112 17:02:47.982655 872 apf_controller.go:377] Starting API Priority and Fairness config controller1067machine # [ 21.346099] k3s[872]: I1112 17:02:47.982965 872 cluster_authentication_trust_controller.go:459] Starting cluster_authentication_trust_controller controller1068machine # [ 21.347967] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="Waiting for caches to sync" logger=k3s1069machine # [ 21.349327] k3s[872]: I1112 17:02:47.983188 872 storage_readiness_hook.go:70] Storage is ready for all registered resources1070machine # [ 21.350838] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="Starting apiserver lease garbage collector" logger=k3s1071machine # [ 21.352363] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="Waiting for caches to sync" logger=k3s1072machine # [ 21.353650] k3s[872]: I1112 17:02:47.972586 872 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"1073machine # [ 21.356497] k3s[872]: I1112 17:02:47.972604 872 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1074machine # [ 21.358513] k3s[872]: I1112 17:02:47.997997 872 controller.go:142] Starting OpenAPI controller1075machine # [ 21.359785] k3s[872]: I1112 17:02:47.998593 872 controller.go:90] Starting OpenAPI V3 controller1076machine # [ 21.361123] k3s[872]: I1112 17:02:47.998620 872 naming_controller.go:305] Starting NamingConditionController1077machine # [ 21.362549] k3s[872]: I1112 17:02:47.998681 872 nonstructuralschema_controller.go:202] Starting NonStructuralSchemaConditionController1078machine # [ 21.364293] k3s[872]: I1112 17:02:47.998708 872 apiapproval_controller.go:196] Starting KubernetesAPIApprovalPolicyConformantConditionController1079machine # [ 21.366208] k3s[872]: time="2026-11-12T17:02:47Z" level=info msg="Starting CRDFinalizer" logger=k3s1080machine # [ 21.367514] k3s[872]: I1112 17:02:47.998778 872 crdregistration_controller.go:114] Starting crd-autoregister controller1081machine # [ 21.369075] k3s[872]: I1112 17:02:47.998806 872 shared_informer.go:381] "Waiting for caches to sync" controller="crd-autoregister"1082machine # [ 21.370672] k3s[872]: I1112 17:02:47.998861 872 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1083machine # [ 21.372816] k3s[872]: I1112 17:02:47.998976 872 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1084machine # [ 21.374938] k3s[872]: I1112 17:02:47.999358 872 repairip.go:210] Starting ipallocator-repair-controller1085machine # [ 21.376269] k3s[872]: I1112 17:02:47.999378 872 shared_informer.go:381] "Waiting for caches to sync" controller="ipallocator-repair-controller"1086machine # [ 21.378025] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/kyix6dphrkrxwz27rcspc3n86sqsafq8-k3s-airgap-images-arm64.tar.zst"1087machine # [ 21.394763] k3s[872]: I1112 17:02:48.075321 872 shared_informer.go:409] "Caches are synced"1088machine # [ 21.397985] k3s[872]: I1112 17:02:48.077037 872 policy_source.go:248] refreshing policies1089machine # [ 21.399565] k3s[872]: I1112 17:02:48.077288 872 cache.go:39] Caches are synced for LocalAvailability controller1090machine # [ 21.402012] k3s[872]: I1112 17:02:48.077418 872 cache.go:39] Caches are synced for APIServiceRegistrationController controller1091machine # [ 21.405141] k3s[872]: I1112 17:02:48.077725 872 shared_informer.go:409] "Caches are synced"1092machine # [ 21.412213] k3s[872]: I1112 17:02:48.077741 872 policy_source.go:248] refreshing policies1093machine # [ 21.413523] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Caches are synced" logger=k3s1094machine # [ 21.414795] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Creating default ServiceCIDR" CIDRs="[10.43.0.0/16]" logger=k3s1095machine # [ 21.416410] k3s[872]: I1112 17:02:48.078516 872 handler_discovery.go:459] Starting ResourceDiscoveryManager1096machine # [ 21.417902] k3s[872]: I1112 17:02:48.082939 872 apf_controller.go:382] Running API Priority and Fairness config worker1097machine # [ 21.419377] k3s[872]: I1112 17:02:48.082983 872 apf_controller.go:385] Running API Priority and Fairness periodic rebalancing process1098machine # [ 21.421100] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Caches are synced" logger=k3s1099machine # [ 21.422258] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Caches are synced" logger=k3s1100machine # [ 21.423489] k3s[872]: I1112 17:02:48.094362 872 cache.go:39] Caches are synced for RemoteAvailability controller1101machine # [ 21.428260] k3s[872]: I1112 17:02:48.099081 872 shared_informer.go:388] "Caches are synced" controller="crd-autoregister"1102machine # [ 21.429946] k3s[872]: I1112 17:02:48.099750 872 shared_informer.go:388] "Caches are synced" controller="ipallocator-repair-controller"1103machine # [ 21.431752] k3s[872]: I1112 17:02:48.107464 872 aggregator.go:187] initial CRD sync complete...1104machine # [ 21.435199] k3s[872]: I1112 17:02:48.107520 872 autoregister_controller.go:144] Starting autoregister controller1105machine # [ 21.436790] k3s[872]: I1112 17:02:48.107537 872 cache.go:32] Waiting for caches to sync for autoregister controller1106machine # [ 21.438232] k3s[872]: I1112 17:02:48.107565 872 cache.go:39] Caches are synced for autoregister controller1107machine # [ 21.444110] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Setting default ServiceCIDR condition Ready to True" logger=k3s1108machine # [ 21.458420] k3s[872]: I1112 17:02:48.139007 872 cidrallocator.go:302] created ClusterIP allocator for Service CIDR 10.43.0.0/161109machine # [ 21.468977] k3s[872]: I1112 17:02:48.149279 872 controller.go:667] quota admission added evaluator for: leases.coordination.k8s.io1110machine # [ 21.472085] k3s[872]: I1112 17:02:48.152666 872 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161111machine # [ 21.473764] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Creating default ServiceCIDR" CIDRs="[10.43.0.0/16]" logger=k3s1112machine # [ 21.475358] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Inconsistent ServiceCIDR status" controllerCIDRs="[10.43.0.0/16]" logger=k3s serviceCIDR= serviceCIDRs="[]"1113machine # [ 21.480144] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Event occurred" apiVersion=networking.k8s.io/v1 fieldPath= kind=ServiceCIDR logger=k3s message="The default ServiceCIDR [] does not match the controller flag configurations [10.43.0.0/16]" object= reason=KubernetesDefaultServiceCIDRInconsistent type=Warning1114machine # [ 21.488292] k3s[872]: I1112 17:02:48.165168 872 shared_informer.go:388] "Caches are synced" controller="node_authorizer"1115machine # [ 21.496122] k3s[872]: E1112 17:02:48.176684 872 controller.go:95] Unable to perform initial Kubernetes service initialization: namespaces "default" not found1116machine # [ 21.512913] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Caches are synced" logger=k3s1117machine # [ 22.112497] k3s[872]: time="2026-11-12T17:02:48Z" level=info msg="Polling for API server readiness: GET /readyz failed: unknown"1118machine # [ 22.308292] k3s[872]: I1112 17:02:48.986574 872 storage_scheduling.go:137] created PriorityClass system-node-critical with value 20000010001119machine # [ 22.315837] k3s[872]: I1112 17:02:48.996393 872 storage_scheduling.go:137] created PriorityClass system-cluster-critical with value 20000000001120machine # [ 22.317975] k3s[872]: I1112 17:02:48.996426 872 storage_scheduling.go:153] all system priority classes are created successfully or already exist.1121machine # [ 22.926350] k3s[872]: I1112 17:02:49.606915 872 controller.go:667] quota admission added evaluator for: roles.rbac.authorization.k8s.io1122machine # [ 22.966786] k3s[872]: I1112 17:02:49.646817 872 controller.go:667] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io1123machine # [ 23.013977] k3s[872]: I1112 17:02:49.694510 872 alloc.go:329] "allocated clusterIPs" service="default/kubernetes" clusterIPs={"IPv4":"10.43.0.1"}1124machine # [ 23.020241] k3s[872]: W1112 17:02:49.700840 872 lease.go:265] Resetting endpoints for master service "kubernetes" to [10.0.2.15]1125machine # [ 23.024114] k3s[872]: I1112 17:02:49.703497 872 controller.go:667] quota admission added evaluator for: endpoints1126machine # [ 23.029540] k3s[872]: I1112 17:02:49.710103 872 controller.go:667] quota admission added evaluator for: endpointslices.discovery.k8s.io1127machine # [ 24.127208] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="Kube API server is now running"1128machine # [ 24.128627] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="k3s is up and running"1129machine # [ 24.130002] systemd[1]: Started k3s service.1130machine # [ 24.130733] systemd[1]: Reached target Multi-User System.1131machine # [ 24.131547] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="Waiting for untainted node"1132machine # [ 24.136187] systemd[1]: Startup finished in 892ms (kernel) + 3.709s (initrd) + 19.524s (userspace) = 24.127s.1133machine # [ 24.137665] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="Creating k3s-supervisor event broadcaster"1134machine # [ 24.139032] k3s[872]: time="2026-11-12T17:02:50Z" 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=Normal1135machine # [ 24.160196] k3s[872]: E1112 17:02:50.840651 872 options.go:205] The manifest file is empty, ignoring.1136machine # [ 24.164126] k3s[872]: I1112 17:02:50.844144 872 controllermanager.go:204] "Starting" version="v1.36.5+k3s1"1137machine # [ 24.168264] k3s[872]: I1112 17:02:50.844180 872 controllermanager.go:206] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1138machine # [ 24.174818] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="Creating embedded CRD etcdsnapshotfiles.k3s.cattle.io"1139machine # [ 24.177074] k3s[872]: I1112 17:02:50.857706 872 secure_serving.go:214] Serving securely on 127.0.0.1:102571140machine # [ 24.181248] k3s[872]: I1112 17:02:50.861872 872 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1141machine # [ 24.184075] k3s[872]: I1112 17:02:50.863600 872 shared_informer.go:402] "Waiting for caches to sync"1142machine # [ 24.185423] k3s[872]: I1112 17:02:50.863667 872 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"1143machine # [ 24.190291] k3s[872]: I1112 17:02:50.863819 872 tlsconfig.go:243] "Starting DynamicServingCertificateController"1144machine # [ 24.192038] k3s[872]: I1112 17:02:50.863888 872 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1145machine # [ 24.195139] k3s[872]: I1112 17:02:50.863902 872 shared_informer.go:402] "Waiting for caches to sync"1146machine # [ 24.197418] k3s[872]: I1112 17:02:50.863915 872 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1147machine # [ 24.200137] k3s[872]: I1112 17:02:50.863928 872 shared_informer.go:402] "Waiting for caches to sync"1148machine # [ 24.201464] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="Creating embedded CRD addons.k3s.cattle.io"1149machine # [ 24.232399] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="Creating embedded CRD helmchartconfigs.helm.cattle.io"1150machine # [ 24.260120] k3s[872]: I1112 17:02:50.939266 872 controller.go:667] quota admission added evaluator for: serviceaccounts1151machine # [ 24.262024] k3s[872]: time="2026-11-12T17:02:50Z" level=info msg="Creating embedded CRD helmcharts.helm.cattle.io"1152machine # [ 24.288575] k3s[872]: I1112 17:02:50.969156 872 shared_informer.go:409] "Caches are synced"1153machine # [ 24.292272] k3s[872]: I1112 17:02:50.971372 872 shared_informer.go:409] "Caches are synced"1154machine # [ 24.293739] k3s[872]: I1112 17:02:50.971386 872 shared_informer.go:409] "Caches are synced"1155machine # [ 24.295057] k3s[872]: I1112 17:02:50.971778 872 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podgroup-protection-controller" requiredFeatureGates=["GenericWorkload"]1156machine # [ 24.300256] k3s[872]: I1112 17:02:50.971940 872 controllermanager.go:641] "Warning: skipping controller" controller="podgroup-protection-controller"1157machine # [ 24.316518] k3s[872]: I1112 17:02:50.997050 872 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1158machine # [ 24.320936] k3s[872]: I1112 17:02:51.001510 872 shared_informer.go:402] "Waiting for caches to sync"1159machine # [ 24.344146] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Waiting for CRD addons.k3s.cattle.io to become available"1160machine # [ 24.354086] k3s[872]: I1112 17:02:51.034647 872 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1161machine # [ 24.372108] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Done waiting for CRD addons.k3s.cattle.io to become available"1162machine # [ 24.373907] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Waiting for CRD helmchartconfigs.helm.cattle.io to become available"1163machine # [ 24.387595] k3s[872]: I1112 17:02:51.068142 872 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1164machine # [ 24.440331] k3s[872]: I1112 17:02:51.120908 872 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1165machine # [ 24.525011] k3s[872]: I1112 17:02:51.205537 872 shared_informer.go:409] "Caches are synced"1166machine # [ 24.574876] k3s[872]: I1112 17:02:51.255435 872 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="resourcepoolstatusrequest-controller" requiredFeatureGates=["DRAResourcePoolStatus"]1167machine # [ 24.580373] k3s[872]: I1112 17:02:51.258446 872 controllermanager.go:641] "Warning: skipping controller" controller="resourcepoolstatusrequest-controller"1168machine # [ 24.582322] k3s[872]: I1112 17:02:51.258487 872 controllermanager.go:641] "Warning: skipping controller" controller="storage-version-migrator-controller"1169machine # [ 24.901216] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Done waiting for CRD helmchartconfigs.helm.cattle.io to become available"1170machine # [ 24.904275] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Waiting for CRD helmcharts.helm.cattle.io to become available"1171machine # [ 24.908108] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Done waiting for CRD helmcharts.helm.cattle.io to become available"1172machine # [ 24.910956] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-40.1.5+up40.1.0.tgz"1173machine # [ 24.916201] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-40.1.5+up40.1.0.tgz"1174machine # [ 24.918165] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml"1175machine # [ 24.921322] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml"1176machine # [ 24.922974] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml"1177machine # [ 24.928259] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml"1178machine # [ 24.929959] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/runtimes.yaml"1179machine # [ 24.931600] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml"1180machine # [ 24.934772] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Starting dynamiclistener CN filter node controller with SANs: [127.0.0.1 ::1 localhost machine 10.0.2.15 fec0::e927:9041:2fbc:de71 10.43.0.1 kubernetes kubernetes.default kubernetes.default.svc kubernetes.default.svc.cluster.local]"1181machine # [ 24.938592] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tunnel server egress proxy mode: agent"1182machine # [ 24.956113] k3s[872]: I1112 17:02:51.636615 872 range_allocator.go:113] "No Secondary Service CIDR provided. Skipping filtering out secondary service addresses" logger="node-ipam-controller"1183[25.72s] machine: (finished: waiting for unit k3s.service, in 25.72 seconds)1184[25.72s] machine: waiting for unit rustfs-setup.service1185[25.77s] machine: (finished: waiting for unit rustfs-setup.service, in 0.04 seconds)1186[25.77s] machine: waiting for unit postgresql.service1187machine # [ 25.031972] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller"1188machine # [ 25.035237] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Creating deploy event broadcaster"1189machine # [ 25.041861] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Creating helm-controller event broadcaster"1190machine # [ 25.043412] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Starting /v1, Kind=Node controller"1191machine # [ 25.048187] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Registered handlers for helm-controller-chart-registration" logger=k3s/helm-controller1192machine # [ 25.065422] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Unable to set control-plane role label: nodes \"machine\" not found"1193machine # [ 25.087239] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Cluster dns configmap has been set successfully"1194[25.87s] machine: (finished: waiting for unit postgresql.service, in 0.10 seconds)1195[25.87s] subtest: chart deploys and becomes ready1196??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1197 File "/nix/store/81dgbf2d9k9llajgi9597ahypdjn5iam-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391198[25.87s] machine: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s1199??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1200 File "/nix/store/81dgbf2d9k9llajgi9597ahypdjn5iam-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391201machine # [ 25.149464] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/klipper-helm:v0.13.3-build20260727"1202machine # [ 25.156349] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/klipper-helm@sha256:5425a2b4613d2458dbdff99218e8d487ebb59c20e7a941f061c0777070f0aac1"1203machine # [ 25.160870] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/klipper-lb:v0.4.17"1204machine # [ 25.162299] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/klipper-lb@sha256:910944bb0bd94f060a82a56ca1ea1c577d3e49b3473a093a47a985f32e92d94a"1205machine # [ 25.165871] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.37"1206machine # [ 25.168470] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/local-path-provisioner@sha256:e757967a5ec338f6a9b371c5a9688bedaa8c3578ea3dd4db329ea0084be0a86f"1207machine # [ 25.173069] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/mirrored-coredns-coredns:1.14.7"1208machine # [ 25.174651] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/mirrored-coredns-coredns@sha256:7efd3c635b03efd68c4e8398fc45f0d993d0e9ab016f72c1cefb0fd6d01aa286"1209machine # [ 25.177013] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/mirrored-library-busybox:1.37.0"1210machine # [ 25.179481] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/mirrored-library-busybox@sha256:101b4afd76732482eff9b95cae5f94bcf295e521fbec4e01b69c5421f3f3f3e5"1211machine # [ 25.182686] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/mirrored-library-traefik:3.7.13"1212machine # [ 25.186044] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/mirrored-library-traefik@sha256:f86a2cab1b5c649070c49f883c743dd32d8485a56e3368c5f93b9e91f1e91259"1213machine # [ 25.189033] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/mirrored-metrics-server:v0.9.0"1214machine # [ 25.192382] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/mirrored-metrics-server@sha256:d9862115e7c7881280d3d75ca26bda8ffc0fc213315979575bf23ce9826205c0"1215machine # [ 25.194919] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Imported docker.io/rancher/mirrored-pause:3.10.2"1216machine # [ 25.197519] k3s[872]: time="2026-11-12T17:02:51Z" level=info msg="Tagged docker.io/rancher/mirrored-pause@sha256:f548e0e8e3dc1896ca956272154dde3314e8cc4fde0a57577ee9fa1c63f5baf4"1217machine # Error from server (NotFound): namespaces "niks3" not found1218machine # [ 25.473750] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Imported 8 images from /var/lib/rancher/k3s/agent/images/nixos/kyix6dphrkrxwz27rcspc3n86sqsafq8-k3s-airgap-images-arm64.tar.zst in 4.1212257s"1219machine # [ 25.476804] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/yzhvi7gwn7ndzz7mf0z3a3si3rl1k4w4-niks3-server.tar"1220machine # [ 25.551489] k3s[872]: W1112 17:02:52.232023 872 probe.go:275] Flexvolume plugin directory at /usr/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating.1221machine # [ 25.680584] k3s[872]: time="2026-11-12T17:02:52Z" 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__e927_9041_2fbc_de71-7f5ffa:fec0::e927:9041:2fbc:de71 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=0F6948538D22A7AE504108EA0B738CE1EE8B28BC]"1222machine # [ 25.732669] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Active TLS secret kube-system/k3s-serving (ver=241) (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__e927_9041_2fbc_de71-7f5ffa:fec0::e927:9041:2fbc:de71 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=0F6948538D22A7AE504108EA0B738CE1EE8B28BC]"1223machine # [ 25.845342] k3s[872]: time="2026-11-12T17:02:52Z" 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::e927:9041:2fbc:de71 --node-labels= --read-only-port=0"1224machine # [ 25.850482] k3s[872]: 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.1225machine # [ 25.866758] k3s[872]: I1112 17:02:52.547352 872 server.go:541] "Kubelet version" kubeletVersion="v1.36.5+k3s1"1226machine # [ 25.869193] k3s[872]: I1112 17:02:52.548969 872 server.go:543] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1227machine # [ 25.870786] k3s[872]: I1112 17:02:52.549016 872 watchdog_linux.go:94] "Systemd watchdog is not enabled"1228machine # [ 25.873366] k3s[872]: I1112 17:02:52.549055 872 watchdog_linux.go:137] "Systemd watchdog is not enabled or the interval is invalid, so health checking will not be started."1229machine # [ 25.875677] k3s[872]: I1112 17:02:52.556279 872 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt"1230machine # [ 25.894723] k3s[872]: I1112 17:02:52.571894 872 server.go:1444] "Using cgroup driver setting received from the CRI runtime" cgroupDriver="systemd"1231machine # [ 25.901018] k3s[872]: I1112 17:02:52.581636 872 server.go:804] "--cgroups-per-qos enabled, but --cgroup-root was not specified. Defaulting to /"1232machine # [ 25.903581] k3s[872]: I1112 17:02:52.581677 872 server.go:865] "NoSwap is set due to memorySwapBehavior not specified" memorySwapBehavior="" FailSwapOn=false1233machine # [ 25.906905] k3s[872]: I1112 17:02:52.582011 872 container_manager_linux.go:273] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]1234machine # [ 25.909037] k3s[872]: I1112 17:02:52.582039 872 container_manager_linux.go:278] "Creating Container Manager object based on Node Config" nodeConfig={"NodeName":"machine","RuntimeCgroupsName":"","SystemCgroupsName":"","KubeletCgroupsName":"","KubeletOOMScoreAdj":-999,"ContainerRuntime":"","CgroupsPerQOS":true,"CgroupRoot":"/","CgroupDriver":"systemd","KubeletRootDir":"/var/lib/kubelet","ProtectKernelDefaults":false,"KubeReservedCgroupName":"","SystemReservedCgroupName":"","ReservedSystemCPUs":{},"EnforceNodeAllocatable":{"pods":{}},"KubeReserved":null,"SystemReserved":null,"HardEvictionThresholds":[{"Signal":"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,"MemoryReservationPolicy":"None","PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null,"CgroupVersion":2}1235machine # [ 25.924035] k3s[872]: I1112 17:02:52.582296 872 topology_manager.go:172] "Creating topology manager with none policy"1236machine # [ 25.925493] k3s[872]: I1112 17:02:52.582310 872 container_manager_linux.go:309] "Creating device plugin manager"1237machine # [ 25.926967] k3s[872]: I1112 17:02:52.582406 872 container_manager_linux.go:318] "Creating Dynamic Resource Allocation (DRA) manager"1238machine # [ 25.933229] k3s[872]: I1112 17:02:52.613820 872 state_mem.go:45] "Initialized" logger="CPUManager state memory"1239machine # [ 25.934881] k3s[872]: I1112 17:02:52.614278 872 kubelet.go:485] "Attempting to sync node with API server"1240machine # [ 25.955664] k3s[872]: I1112 17:02:52.614300 872 kubelet.go:386] "Adding static pod path" path="/var/lib/rancher/k3s/agent/pod-manifests"1241machine # [ 25.959133] k3s[872]: I1112 17:02:52.614444 872 kubelet.go:397] "Adding apiserver pod source"1242machine # [ 25.960585] k3s[872]: I1112 17:02:52.614465 872 apiserver.go:41] "Waiting for node sync before watching apiserver pods"1243machine # [ 25.962205] k3s[872]: I1112 17:02:52.618490 872 kuberuntime_manager.go:308] "Container runtime initialized" containerRuntime="containerd" version="2.3.4-k3s1.36" apiVersion="v1"1244machine # [ 25.964974] k3s[872]: I1112 17:02:52.638101 872 kubelet.go:1002] "Not starting ClusterTrustBundle informer because we are in static kubelet mode or the ClusterTrustBundleProjection featuregate is disabled"1245machine # [ 25.968206] k3s[872]: I1112 17:02:52.638152 872 kubelet.go:1029] "Not starting PodCertificateRequest manager because we are in static kubelet mode or the PodCertificateProjection feature gate is disabled"1246machine # [ 25.972360] k3s[872]: I1112 17:02:52.652753 872 server.go:1280] "Started kubelet"1247machine # [ 25.974188] k3s[872]: I1112 17:02:52.654494 872 server.go:193] "Starting to listen" address="0.0.0.0" port=102501248machine # [ 25.977296] k3s[872]: I1112 17:02:52.656005 872 server.go:354] "Adding debug handlers to kubelet server"1249machine # [ 25.978801] k3s[872]: I1112 17:02:52.656959 872 fs_resource_analyzer.go:69] "Starting FS ResourceAnalyzer"1250machine # [ 25.981074] k3s[872]: I1112 17:02:52.659754 872 ratelimit.go:56] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=101251machine # [ 25.982964] k3s[872]: I1112 17:02:52.659876 872 server_v1.go:49] "podresources" method="list" useActivePods=true1252machine # [ 25.984706] k3s[872]: I1112 17:02:52.660103 872 server.go:264] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock"1253machine # [ 25.990531] k3s[872]: I1112 17:02:52.671158 872 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"1254machine # [ 25.995371] k3s[872]: I1112 17:02:52.671315 872 tlsconfig.go:243] "Starting DynamicServingCertificateController"1255machine # [ 26.000159] k3s[872]: I1112 17:02:52.674193 872 volume_manager.go:310] "Starting Kubelet Volume Manager"1256machine # [ 26.001561] k3s[872]: E1112 17:02:52.674918 872 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1257machine # [ 26.003425] k3s[872]: E1112 17:02:52.675249 872 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1258machine # [ 26.007814] k3s[872]: I1112 17:02:52.678217 872 desired_state_of_world_populator.go:146] "Desired state populator starts to run"1259machine # [ 26.011536] k3s[872]: I1112 17:02:52.678302 872 reconciler.go:29] "Reconciler: start to sync state"1260machine # [ 26.014537] k3s[872]: I1112 17:02:52.686576 872 factory.go:222] Registration of the systemd container factory successfully1261machine # [ 26.016384] k3s[872]: E1112 17:02:52.686758 872 kubelet.go:1725] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"1262machine # [ 26.019333] k3s[872]: I1112 17:02:52.687160 872 factory.go:220] Registration of the crio container factory failed: Get "http://%2Fvar%2Frun%2Fcrio%2Fcrio.sock/info": dial unix /var/run/crio/crio.sock: connect: no such file or directory1263machine # [ 26.022476] k3s[872]: E1112 17:02:52.689624 872 nodelease.go:50] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"machine\" not found" node="machine"1264machine # [ 26.024792] k3s[872]: I1112 17:02:52.691970 872 factory.go:222] Registration of the containerd container factory successfully1265machine # [ 26.049295] k3s[872]: I1112 17:02:52.729776 872 cpu_manager.go:235] "Starting" policy="none"1266machine # [ 26.051154] k3s[872]: I1112 17:02:52.729802 872 cpu_manager.go:236] "Reconciling" reconcilePeriod="10s"1267machine # [ 26.052965] k3s[872]: I1112 17:02:52.731012 872 controllermanager.go:689] "Warning: controller is disabled" controller="node-route-controller"1268machine # [ 26.055103] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Unable to set control-plane role label: nodes \"machine\" not found"1269machine # [ 26.057681] k3s[872]: I1112 17:02:52.731422 872 state_mem.go:45] "Initialized" logger="CPUManager state checkpoint.CPUManager state memory"1270machine # [ 26.059602] k3s[872]: I1112 17:02:52.733622 872 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv6"1271machine # [ 26.064906] k3s[872]: I1112 17:02:52.745036 872 policy_none.go:50] "Start"1272machine # [ 26.066035] k3s[872]: I1112 17:02:52.745076 872 memory_manager.go:190] "Starting memorymanager" policy="None"1273machine # [ 26.068043] k3s[872]: I1112 17:02:52.745099 872 state_mem.go:40] "Initializing new in-memory state store" logger="Memory Manager state checkpoint"1274machine # [ 26.072338] k3s[872]: I1112 17:02:52.752959 872 policy_none.go:44] "Start"1275machine # [ 26.079827] systemd[1]: Created slice libcontainer container kubepods.slice.1276machine # [ 26.094409] k3s[872]: E1112 17:02:52.775004 872 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1277machine # [ 26.097304] k3s[872]: E1112 17:02:52.777197 872 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1278machine # [ 26.110336] systemd[1]: Created slice libcontainer container kubepods-burstable.slice.1279machine # [ 26.118459] systemd[1]: Created slice libcontainer container kubepods-besteffort.slice.1280machine # [ 26.143016] k3s[872]: E1112 17:02:52.823560 872 manager.go:525] "Failed to read data from checkpoint" err="checkpoint is not found" checkpoint="kubelet_internal_checkpoint"1281machine # [ 26.147824] k3s[872]: I1112 17:02:52.823746 872 eviction_manager.go:194] "Eviction manager: starting control loop"1282machine # [ 26.151003] k3s[872]: I1112 17:02:52.823775 872 container_log_manager.go:146] "Initializing container log rotate workers" workers=1 monitorPeriod="10s"1283machine # [ 26.153851] k3s[872]: I1112 17:02:52.824565 872 plugin_manager.go:121] "Starting Kubelet Plugin Manager"1284machine # [ 26.156711] k3s[872]: E1112 17:02:52.827952 872 eviction_manager.go:272] "eviction manager: failed to check if we have separate container filesystem. Ignoring." err="no imagefs label for configured runtime"1285machine # [ 26.159293] k3s[872]: E1112 17:02:52.828420 872 eviction_manager.go:297] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"machine\" not found"1286machine # [ 26.171876] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller"1287machine # [ 26.185339] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting batch/v1, Kind=Job controller"1288machine # [ 26.188161] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting /v1, Kind=ServiceAccount controller"1289machine # [ 26.189989] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting /v1, Kind=Secret controller"1290machine # [ 26.192741] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting /v1, Kind=ConfigMap controller"1291machine # [ 26.195336] k3s[872]: E1112 17:02:52.875288 872 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1292machine # [ 26.200452] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Imported docker.io/library/niks3-server:1.17.1-aarch64-linux"1293machine # [ 26.205764] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller"1294machine # [ 26.207800] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller"1295machine # [ 26.210514] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Tagged docker.io/library/niks3-server@sha256:ff080305935320bb67d14bb1641c0620458d0d84d8b8ad4cbdd7ba2f0e3ff722"1296machine # [ 26.213744] k3s[872]: I1112 17:02:52.888580 872 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv4"1297machine # [ 26.215520] k3s[872]: I1112 17:02:52.888641 872 status_manager.go:277] "Starting to sync pod status with apiserver"1298machine # [ 26.219060] k3s[872]: I1112 17:02:52.888684 872 kubelet.go:2622] "Starting kubelet main sync loop"1299machine # [ 26.220736] k3s[872]: E1112 17:02:52.888952 872 kubelet.go:2646] "Skipping pod synchronization" err="PLEG is not healthy: pleg has yet to be successful"1300machine # [ 26.238469] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Imported 1 images from /var/lib/rancher/k3s/agent/images/nixos/yzhvi7gwn7ndzz7mf0z3a3si3rl1k4w4-niks3-server.tar in 761.73844ms"1301machine # [ 26.248198] k3s[872]: I1112 17:02:52.925975 872 kubelet_node_status.go:75] "Attempting to register node" node="machine"1302machine # [ 26.256786] k3s[872]: I1112 17:02:52.937026 872 kubelet_node_status.go:78] "Successfully registered node" node="machine"1303machine # [ 26.274119] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Annotations and labels have been set successfully on node: machine"1304machine # [ 26.276561] k3s[872]: time="2026-11-12T17:02:52Z" level=info msg="Starting flannel with backend vxlan"1305machine # [ 26.381720] k3s[872]: I1112 17:02:53.062297 872 kubelet_node_status.go:431] "Fast updating node status as it just became ready"1306machine # [ 26.526878] k3s[872]: I1112 17:02:53.206020 872 server.go:228] "Successfully retrieved NodeIPs" NodeIPs=["10.0.2.15","fec0::e927:9041:2fbc:de71"]1307machine # [ 26.529863] k3s[872]: E1112 17:02:53.207122 872 server.go:265] "Kube-proxy configuration may be incomplete or incorrect" err="nodePortAddresses is unset; NodePort connections will be accepted on all local IPs. Consider using `--nodeport-addresses primary`"1308machine # [ 26.555328] k3s[872]: I1112 17:02:53.235766 872 server.go:274] "kube-proxy running in dual-stack mode" primary ipFamily="IPv4"1309machine # [ 26.560045] k3s[872]: I1112 17:02:53.235856 872 server_linux.go:137] "Using iptables Proxier"1310machine # [ 26.573412] k3s[872]: I1112 17:02:53.253755 872 proxier.go:241] "Setting route_localnet=1 to allow node-ports on localhost; to change this either disable iptables.localhostNodePorts (--iptables-localhost-nodeports) or set nodePortAddresses (--nodeport-addresses) to filter loopback addresses" ipFamily="IPv4"1311machine # [ 26.584366] k3s[872]: I1112 17:02:53.264758 872 server.go:539] "Version info" version="v1.36.5+k3s1"1312machine # [ 26.589312] k3s[872]: I1112 17:02:53.264805 872 server.go:541] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1313machine # [ 26.590902] k3s[872]: I1112 17:02:53.268223 872 config.go:200] "Starting service config controller"1314machine # [ 26.596326] k3s[872]: I1112 17:02:53.268256 872 shared_informer.go:381] "Waiting for caches to sync" controller="service config"1315machine # [ 26.598085] k3s[872]: I1112 17:02:53.268275 872 config.go:106] "Starting endpoint slice config controller"1316machine # [ 26.599896] k3s[872]: I1112 17:02:53.268289 872 shared_informer.go:381] "Waiting for caches to sync" controller="endpoint slice config"1317machine # [ 26.601785] k3s[872]: I1112 17:02:53.268303 872 config.go:403] "Starting serviceCIDR config controller"1318machine # [ 26.603113] k3s[872]: I1112 17:02:53.268311 872 shared_informer.go:381] "Waiting for caches to sync" controller="serviceCIDR config"1319machine # [ 26.609842] k3s[872]: I1112 17:02:53.273845 872 config.go:309] "Starting node config controller"1320machine # [ 26.611279] k3s[872]: I1112 17:02:53.273896 872 shared_informer.go:381] "Waiting for caches to sync" controller="node config"1321machine # [ 26.613242] k3s[872]: I1112 17:02:53.273910 872 shared_informer.go:388] "Caches are synced" controller="node config"1322machine # [ 26.688994] k3s[872]: I1112 17:02:53.369237 872 shared_informer.go:388] "Caches are synced" controller="serviceCIDR config"1323machine # [ 26.690724] k3s[872]: I1112 17:02:53.369365 872 shared_informer.go:388] "Caches are synced" controller="service config"1324machine # [ 26.692629] k3s[872]: I1112 17:02:53.369385 872 shared_informer.go:388] "Caches are synced" controller="endpoint slice config"1325machine # Error from server (NotFound): namespaces "niks3" not found1326machine # [ 26.937286] k3s[872]: I1112 17:02:53.617361 872 apiserver.go:51] "Watching apiserver"1327machine # [ 26.999769] k3s[872]: I1112 17:02:53.680270 872 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world"1328machine # [ 27.006176] k3s[872]: I1112 17:02:53.686694 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmcharts.helm.cattle.io"1329machine # [ 27.008862] k3s[872]: I1112 17:02:53.686832 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="limitranges"1330machine # [ 27.011092] k3s[872]: I1112 17:02:53.686881 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpoints"1331machine # [ 27.013410] k3s[872]: I1112 17:02:53.686903 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="horizontalpodautoscalers.autoscaling"1332machine # [ 27.016217] k3s[872]: I1112 17:02:53.686934 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="csistoragecapacities.storage.k8s.io"1333machine # [ 27.018831] k3s[872]: I1112 17:02:53.687035 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="daemonsets.apps"1334machine # [ 27.021277] k3s[872]: I1112 17:02:53.687057 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="controllerrevisions.apps"1335machine # [ 27.023801] k3s[872]: I1112 17:02:53.687084 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="jobs.batch"1336machine # [ 27.026158] k3s[872]: I1112 17:02:53.687105 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="cronjobs.batch"1337machine # [ 27.028568] k3s[872]: I1112 17:02:53.687129 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="roles.rbac.authorization.k8s.io"1338machine # [ 27.031186] k3s[872]: I1112 17:02:53.687147 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="serviceaccounts"1339machine # [ 27.033623] k3s[872]: I1112 17:02:53.687198 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="podtemplates"1340machine # [ 27.035959] k3s[872]: I1112 17:02:53.687295 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="deployments.apps"1341machine # [ 27.038342] k3s[872]: I1112 17:02:53.687323 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="networkpolicies.networking.k8s.io"1342machine # [ 27.040834] k3s[872]: I1112 17:02:53.687348 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="rolebindings.rbac.authorization.k8s.io"1343machine # [ 27.043239] k3s[872]: I1112 17:02:53.687376 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpointslices.discovery.k8s.io"1344machine # [ 27.045707] k3s[872]: I1112 17:02:53.687419 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmchartconfigs.helm.cattle.io"1345machine # [ 27.048113] k3s[872]: I1112 17:02:53.687444 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="poddisruptionbudgets.policy"1346machine # [ 27.050396] k3s[872]: I1112 17:02:53.687476 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="addons.k3s.cattle.io"1347machine # [ 27.052710] k3s[872]: I1112 17:02:53.687504 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="leases.coordination.k8s.io"1348machine # [ 27.055040] k3s[872]: I1112 17:02:53.687527 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="statefulsets.apps"1349machine # [ 27.057369] k3s[872]: I1112 17:02:53.687547 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="replicasets.apps"1350machine # [ 27.059566] k3s[872]: I1112 17:02:53.687570 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="ingresses.networking.k8s.io"1351machine # [ 27.061990] k3s[872]: I1112 17:02:53.687589 872 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="resourceclaimtemplates.resource.k8s.io"1352machine # [ 27.064506] k3s[872]: I1112 17:02:53.721793 872 controller.go:667] quota admission added evaluator for: addons.k3s.cattle.io1353machine # [ 27.066009] k3s[872]: time="2026-11-12T17:02:53Z" 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=Normal1354machine # [ 27.071131] k3s[872]: time="2026-11-12T17:02:53Z" level=info msg="Labels and annotations have been set successfully on node: machine"1355machine # [ 27.107831] k3s[872]: time="2026-11-12T17:02:53Z" 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=Normal1356machine # [ 27.124329] k3s[872]: time="2026-11-12T17:02:53Z" 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=Normal1357machine # [ 27.227411] k3s[872]: time="2026-11-12T17:02:53Z" 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=Normal1358machine # [ 27.243031] k3s[872]: time="2026-11-12T17:02:53Z" 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=Normal1359machine # [ 27.282005] k3s[872]: I1112 17:02:53.962559 872 controller.go:667] quota admission added evaluator for: deployments.apps1360machine # [ 27.300089] k3s[872]: I1112 17:02:53.980018 872 alloc.go:329] "allocated clusterIPs" service="kube-system/kube-dns" clusterIPs={"IPv4":"10.43.0.10"}1361machine # [ 27.315745] k3s[872]: I1112 17:02:53.996313 872 serving.go:417] Generated self-signed cert in-memory1362machine # [ 27.322925] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1363machine # [ 27.386620] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1364machine # [ 27.400208] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1365machine # [ 27.412049] k3s[872]: I1112 17:02:54.092622 872 controller.go:667] quota admission added evaluator for: helmcharts.helm.cattle.io1366machine # [ 27.416043] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1367machine # [ 27.429429] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1368machine # [ 27.448048] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1369machine # [ 27.452001] k3s[872]: I1112 17:02:54.132069 872 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podcertificaterequest-cleaner-controller" requiredFeatureGates=["PodCertificateRequest"]1370machine # [ 27.460071] k3s[872]: I1112 17:02:54.132094 872 controllermanager.go:641] "Warning: skipping controller" controller="podcertificaterequest-cleaner-controller"1371machine # [ 27.484082] k3s[872]: I1112 17:02:54.164543 872 controller.go:667] quota admission added evaluator for: jobs.batch1372machine # [ 27.515881] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1373machine # [ 27.526283] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1374machine # [ 27.563666] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1375machine # [ 27.572033] k3s[872]: time="2026-11-12T17:02:54Z" 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=Normal1376machine # [ 27.581109] k3s[872]: I1112 17:02:54.261738 872 serving.go:417] Generated self-signed cert in-memory1377machine # [ 27.772136] k3s[872]: I1112 17:02:54.448593 872 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller" requiredFeatureGates=["ClusterTrustBundle"]1378machine # [ 27.775357] k3s[872]: I1112 17:02:54.448652 872 controllermanager.go:641] "Warning: skipping controller" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller"1379machine # [ 27.861664] k3s[872]: I1112 17:02:54.542245 872 controllermanager.go:163] Version: v1.36.5+k3s11380machine # [ 27.865132] k3s[872]: I1112 17:02:54.545725 872 secure_serving.go:214] Serving securely on 127.0.0.1:102581381machine # [ 27.866557] k3s[872]: I1112 17:02:54.546439 872 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1382machine # [ 27.872182] k3s[872]: I1112 17:02:54.546462 872 shared_informer.go:402] "Waiting for caches to sync"1383machine # [ 27.873546] k3s[872]: I1112 17:02:54.546504 872 tlsconfig.go:243] "Starting DynamicServingCertificateController"1384machine # [ 27.874964] k3s[872]: I1112 17:02:54.546598 872 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1385machine # [ 27.884421] k3s[872]: I1112 17:02:54.546613 872 shared_informer.go:402] "Waiting for caches to sync"1386machine # [ 27.885772] k3s[872]: I1112 17:02:54.546626 872 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1387machine # [ 27.888218] k3s[872]: I1112 17:02:54.546638 872 shared_informer.go:402] "Waiting for caches to sync"1388machine # [ 27.890652] k3s[872]: time="2026-11-12T17:02:54Z" level=info msg="Creating service-lb-controller event broadcaster"1389machine # [ 27.951684] k3s[872]: I1112 17:02:54.632234 872 controllermanager.go:689] "Warning: controller is disabled" controller="bootstrap-signer-controller"1390machine # [ 27.966745] k3s[872]: I1112 17:02:54.647265 872 shared_informer.go:409] "Caches are synced"1391machine # [ 28.030491] k3s[872]: time="2026-11-12T17:02:54Z" level=info msg="Starting /v1, Kind=Node controller"1392machine # Error from server (NotFound): namespaces "niks3" not found1393machine # [ 28.040128] k3s[872]: time="2026-11-12T17:02:54Z" level=info msg="Starting /v1, Kind=Pod controller"1394machine # [ 28.044070] k3s[872]: time="2026-11-12T17:02:54Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller"1395machine # [ 28.049401] k3s[872]: W1112 17:02:54.728944 872 controllermanager.go:315] "node-route-controller" is disabled1396machine # [ 28.050954] k3s[872]: I1112 17:02:54.729507 872 controllermanager.go:338] Started "cloud-node-controller"1397machine # [ 28.052540] k3s[872]: I1112 17:02:54.729778 872 controllermanager.go:338] Started "cloud-node-lifecycle-controller"1398machine # [ 28.054962] k3s[872]: I1112 17:02:54.730320 872 controllermanager.go:338] Started "service-lb-controller"1399machine # [ 28.056433] k3s[872]: time="2026-11-12T17:02:54Z" level=info msg="Starting discovery.k8s.io/v1, Kind=EndpointSlice controller"1400machine # [ 28.057981] k3s[872]: I1112 17:02:54.731340 872 node_controller.go:179] Sending events to api server.1401machine # [ 28.059313] k3s[872]: I1112 17:02:54.731395 872 node_lifecycle_controller.go:112] Sending events to api server1402machine # [ 28.060917] k3s[872]: I1112 17:02:54.731562 872 node_controller.go:188] Waiting for informer caches to sync1403machine # [ 28.062395] k3s[872]: I1112 17:02:54.731645 872 controller.go:235] Starting service controller1404machine # [ 28.063694] k3s[872]: I1112 17:02:54.731682 872 shared_informer.go:402] "Waiting for caches to sync"1405machine # [ 28.066508] k3s[872]: I1112 17:02:54.747117 872 shared_informer.go:409] "Caches are synced"1406machine # [ 28.067717] k3s[872]: I1112 17:02:54.747185 872 shared_informer.go:409] "Caches are synced"1407machine # [ 28.099230] k3s[872]: I1112 17:02:54.779740 872 controllermanager.go:689] "Warning: controller is disabled" controller="service-lb-controller"1408machine # [ 28.128040] k3s[872]: time="2026-11-12T17:02:54Z" level=info msg="Tunnel authorizer set Kubelet Port 0.0.0.0:10250"1409machine # [ 28.152347] k3s[872]: I1112 17:02:54.832795 872 shared_informer.go:409] "Caches are synced"1410machine # [ 28.155531] k3s[872]: I1112 17:02:54.833042 872 node_controller.go:432] Initializing node machine with cloud provider1411machine # [ 28.173295] k3s[872]: I1112 17:02:54.853333 872 node_controller.go:477] Successfully initialized node machine with cloud provider1412machine # [ 28.176685] k3s[872]: I1112 17:02:54.853873 872 event.go:389] "Event occurred" object="machine" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="Synced" message="Node synced successfully"1413machine # [ 28.187387] k3s[872]: E1112 17:02:54.867888 872 options.go:205] The manifest file is empty, ignoring.1414machine # [ 28.200165] k3s[872]: time="2026-11-12T17:02:54Z" level=info msg="Synced coredns NodeHosts entries for machine"1415machine # [ 28.204384] k3s[872]: I1112 17:02:54.884913 872 server.go:176] "Starting Kubernetes Scheduler" version="v1.36.5+k3s1"1416machine # [ 28.207788] k3s[872]: I1112 17:02:54.884978 872 server.go:178] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1417machine # [ 28.211407] k3s[872]: I1112 17:02:54.892011 872 secure_serving.go:214] Serving securely on 127.0.0.1:102591418machine # [ 28.213940] k3s[872]: I1112 17:02:54.892226 872 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1419machine # [ 28.217286] k3s[872]: I1112 17:02:54.892249 872 shared_informer.go:402] "Waiting for caches to sync"1420machine # [ 28.219456] k3s[872]: I1112 17:02:54.892292 872 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"1421machine # [ 28.224756] k3s[872]: I1112 17:02:54.892444 872 tlsconfig.go:243] "Starting DynamicServingCertificateController"1422machine # [ 28.227641] k3s[872]: I1112 17:02:54.896835 872 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1423machine # [ 28.231428] k3s[872]: I1112 17:02:54.896863 872 shared_informer.go:402] "Waiting for caches to sync"1424machine # [ 28.233293] k3s[872]: I1112 17:02:54.896889 872 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1425machine # [ 28.236706] k3s[872]: I1112 17:02:54.896904 872 shared_informer.go:402] "Waiting for caches to sync"1426machine # [ 28.312205] k3s[872]: I1112 17:02:54.992570 872 shared_informer.go:409] "Caches are synced"1427machine # [ 28.316687] k3s[872]: I1112 17:02:54.996936 872 shared_informer.go:409] "Caches are synced"1428machine # [ 28.318905] k3s[872]: I1112 17:02:54.997004 872 shared_informer.go:409] "Caches are synced"1429machine # [ 28.401534] k3s[872]: I1112 17:02:55.082065 872 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="storageversion-garbage-collector-controller" requiredFeatureGates=["APIServerIdentity","StorageVersionAPI"]1430machine # [ 28.406754] k3s[872]: I1112 17:02:55.082230 872 controllermanager.go:641] "Warning: skipping controller" controller="storageversion-garbage-collector-controller"1431machine # [ 28.899573] k3s[872]: I1112 17:02:55.580105 872 node_lifecycle_controller.go:402] "Controller will reconcile labels" logger="node-lifecycle-controller"1432machine # [ 28.903178] k3s[872]: I1112 17:02:55.580233 872 controllermanager.go:689] "Warning: controller is disabled" controller="cloud-node-lifecycle-controller"1433machine # [ 28.907986] k3s[872]: I1112 17:02:55.580252 872 controllermanager.go:689] "Warning: controller is disabled" controller="selinux-warning-controller"1434machine # [ 28.911047] k3s[872]: I1112 17:02:55.586206 872 node_lifecycle_controller.go:436] "Sending events to api server"1435machine # [ 28.920279] k3s[872]: I1112 17:02:55.586271 872 node_lifecycle_controller.go:443] "Starting node controller"1436machine # [ 28.922492] k3s[872]: I1112 17:02:55.586290 872 shared_informer.go:402] "Waiting for caches to sync"1437machine # [ 28.924701] k3s[872]: I1112 17:02:55.592817 872 shared_informer.go:402] "Waiting for caches to sync"1438machine # [ 28.926767] k3s[872]: I1112 17:02:55.592980 872 replica_set.go:285] "Starting controller" name="replicationcontroller"1439machine # [ 28.932223] k3s[872]: I1112 17:02:55.593003 872 shared_informer.go:402] "Waiting for caches to sync"1440machine # [ 28.936169] k3s[872]: I1112 17:02:55.593070 872 stateful_set.go:234] "Starting stateful set controller"1441machine # [ 28.938259] k3s[872]: I1112 17:02:55.593087 872 shared_informer.go:402] "Waiting for caches to sync"1442machine # [ 28.943695] k3s[872]: I1112 17:02:55.593128 872 expand_controller.go:328] "Starting expand controller"1443machine # [ 28.948182] k3s[872]: I1112 17:02:55.593149 872 shared_informer.go:402] "Waiting for caches to sync"1444machine # [ 28.950241] k3s[872]: I1112 17:02:55.593177 872 namespace_controller.go:202] "Starting namespace controller"1445machine # [ 28.955012] k3s[872]: I1112 17:02:55.593194 872 shared_informer.go:402] "Waiting for caches to sync"1446machine # [ 28.956984] k3s[872]: I1112 17:02:55.593224 872 serviceaccounts_controller.go:117] "Starting service account controller"1447machine # [ 28.959136] k3s[872]: I1112 17:02:55.593238 872 shared_informer.go:402] "Waiting for caches to sync"1448machine # [ 28.964129] k3s[872]: I1112 17:02:55.593306 872 deployment_controller.go:180] "Starting controller" controller="deployment"1449machine # [ 28.966178] k3s[872]: I1112 17:02:55.593322 872 shared_informer.go:402] "Waiting for caches to sync"1450machine # [ 28.967864] k3s[872]: I1112 17:02:55.593396 872 cronjob_controllerv2.go:143] "Starting cronjob controller v2"1451machine # [ 28.972162] k3s[872]: I1112 17:02:55.593412 872 shared_informer.go:402] "Waiting for caches to sync"1452machine # [ 28.973732] k3s[872]: I1112 17:02:55.593454 872 cleaner.go:83] "Starting CSR cleaner controller"1453machine # [ 28.975265] k3s[872]: I1112 17:02:55.593550 872 pv_controller_base.go:318] "Starting persistent volume controller"1454machine # [ 28.980172] k3s[872]: I1112 17:02:55.593569 872 shared_informer.go:402] "Waiting for caches to sync"1455machine # [ 28.981718] k3s[872]: I1112 17:02:55.593636 872 endpointslicemirroring_controller.go:226] "Starting EndpointSliceMirroring controller"1456machine # [ 28.983675] k3s[872]: I1112 17:02:55.593652 872 shared_informer.go:402] "Waiting for caches to sync"1457machine # [ 28.988149] k3s[872]: I1112 17:02:55.593679 872 gc_controller.go:98] "Starting GC controller"1458machine # [ 28.989562] k3s[872]: I1112 17:02:55.593695 872 shared_informer.go:402] "Waiting for caches to sync"1459machine # [ 28.991044] k3s[872]: I1112 17:02:55.593730 872 horizontal.go:204] "Starting HPA controller"1460machine # [ 28.992324] k3s[872]: I1112 17:02:55.593748 872 shared_informer.go:402] "Waiting for caches to sync"1461machine # [ 28.993658] k3s[872]: I1112 17:02:55.593806 872 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-legacy-unknown"1462machine # [ 28.995493] k3s[872]: I1112 17:02:55.593821 872 shared_informer.go:402] "Waiting for caches to sync"1463machine # [ 28.996890] k3s[872]: I1112 17:02:55.593964 872 node_ipam_controller.go:142] "Starting ipam controller"1464machine # [ 28.998397] k3s[872]: I1112 17:02:55.593988 872 shared_informer.go:402] "Waiting for caches to sync"1465machine # [ 28.999745] k3s[872]: I1112 17:02:55.594015 872 vac_protection_controller.go:206] "Starting VAC protection controller"1466machine # [ 29.001309] k3s[872]: I1112 17:02:55.594029 872 shared_informer.go:402] "Waiting for caches to sync"1467machine # [ 29.002570] k3s[872]: I1112 17:02:55.594093 872 servicecidrs_controller.go:137] "Starting" controller="service-cidr-controller"1468machine # [ 29.004208] k3s[872]: I1112 17:02:55.594110 872 shared_informer.go:402] "Waiting for caches to sync"1469machine # [ 29.005693] k3s[872]: I1112 17:02:55.594171 872 replica_set.go:285] "Starting controller" name="replicaset"1470machine # [ 29.007140] k3s[872]: I1112 17:02:55.594186 872 shared_informer.go:402] "Waiting for caches to sync"1471machine # [ 29.008515] k3s[872]: I1112 17:02:55.594252 872 attach_detach_controller.go:334] "Starting attach detach controller"1472machine # [ 29.010046] k3s[872]: I1112 17:02:55.594267 872 shared_informer.go:402] "Waiting for caches to sync"1473machine # [ 29.011337] k3s[872]: I1112 17:02:55.594293 872 pvc_protection_controller.go:172] "Starting PVC protection controller"1474machine # [ 29.012851] k3s[872]: I1112 17:02:55.594307 872 shared_informer.go:402] "Waiting for caches to sync"1475machine # [ 29.014243] k3s[872]: I1112 17:02:55.594421 872 controller.go:753] "Starting resource claim controller"1476machine # [ 29.015613] k3s[872]: I1112 17:02:55.594441 872 shared_informer.go:402] "Waiting for caches to sync"1477machine # [ 29.016968] k3s[872]: I1112 17:02:55.594480 872 legacy_serviceaccount_token_cleaner.go:103] "Starting legacy service account token cleaner controller"1478machine # [ 29.018759] k3s[872]: I1112 17:02:55.594503 872 shared_informer.go:402] "Waiting for caches to sync"1479machine # [ 29.020003] k3s[872]: I1112 17:02:55.594534 872 certificate_controller.go:120] "Starting certificate controller" name="csrapproving"1480machine # [ 29.021634] k3s[872]: I1112 17:02:55.594550 872 shared_informer.go:402] "Waiting for caches to sync"1481machine # [ 29.022969] k3s[872]: I1112 17:02:55.594576 872 clusterroleaggregation_controller.go:176] "Starting ClusterRoleAggregator controller"1482machine # [ 29.024665] k3s[872]: I1112 17:02:55.594590 872 shared_informer.go:402] "Waiting for caches to sync"1483machine # [ 29.025946] k3s[872]: I1112 17:02:55.594615 872 controller.go:174] "Starting ephemeral volume controller"1484machine # [ 29.027273] k3s[872]: I1112 17:02:55.594632 872 shared_informer.go:402] "Waiting for caches to sync"1485machine # [ 29.028584] k3s[872]: I1112 17:02:55.594735 872 device_taint_eviction.go:783] "Starting" controller="device-taint-eviction-controller" numWorkers=81486machine # [ 29.030336] k3s[872]: I1112 17:02:55.594930 872 shared_informer.go:402] "Waiting for caches to sync"1487machine # [ 29.031643] k3s[872]: I1112 17:02:55.595460 872 disruption.go:453] "Sending events to api server."1488machine # [ 29.032985] k3s[872]: I1112 17:02:55.595510 872 disruption.go:460] "Starting disruption controller"1489machine # [ 29.034357] k3s[872]: I1112 17:02:55.595521 872 shared_informer.go:402] "Waiting for caches to sync"1490machine # [ 29.035629] k3s[872]: I1112 17:02:55.595548 872 ttl_controller.go:127] "Starting TTL controller"1491machine # [ 29.036944] k3s[872]: I1112 17:02:55.595566 872 shared_informer.go:402] "Waiting for caches to sync"1492machine # [ 29.038195] k3s[872]: I1112 17:02:55.595591 872 pv_protection_controller.go:81] "Starting PV protection controller"1493machine # [ 29.039752] k3s[872]: I1112 17:02:55.595604 872 shared_informer.go:402] "Waiting for caches to sync"1494machine # [ 29.041215] k3s[872]: I1112 17:02:55.595631 872 taint_eviction.go:283] "Starting" controller="taint-eviction-controller"1495machine # [ 29.042801] k3s[872]: I1112 17:02:55.595690 872 taint_eviction.go:288] "Sending events to API server"1496machine # [ 29.044192] k3s[872]: I1112 17:02:55.595701 872 shared_informer.go:402] "Waiting for caches to sync"1497machine # [ 29.045556] k3s[872]: I1112 17:02:55.595763 872 daemon_controller.go:364] "Starting daemon sets controller"1498machine # [ 29.047039] k3s[872]: I1112 17:02:55.595780 872 shared_informer.go:402] "Waiting for caches to sync"1499machine # [ 29.048435] k3s[872]: I1112 17:02:55.595819 872 tokencleaner.go:117] "Starting token cleaner controller"1500machine # [ 29.049756] k3s[872]: I1112 17:02:55.595836 872 shared_informer.go:402] "Waiting for caches to sync"1501machine # [ 29.051015] k3s[872]: I1112 17:02:55.595873 872 ttlafterfinished_controller.go:112] "Starting TTL after finished controller"1502machine # [ 29.052572] k3s[872]: I1112 17:02:55.595895 872 shared_informer.go:402] "Waiting for caches to sync"1503machine # [ 29.053844] k3s[872]: I1112 17:02:55.595921 872 publisher.go:107] "Starting root CA cert publisher controller"1504machine # [ 29.055271] k3s[872]: I1112 17:02:55.595935 872 shared_informer.go:402] "Waiting for caches to sync"1505machine # [ 29.056711] k3s[872]: I1112 17:02:55.596011 872 endpoints_controller.go:193] "Starting endpoint controller"1506machine # [ 29.058070] k3s[872]: I1112 17:02:55.596031 872 shared_informer.go:402] "Waiting for caches to sync"1507machine # [ 29.059323] k3s[872]: I1112 17:02:55.596090 872 endpointslice_controller.go:280] "Starting endpoint slice controller"1508machine # [ 29.060861] k3s[872]: I1112 17:02:55.596112 872 shared_informer.go:402] "Waiting for caches to sync"1509machine # [ 29.062249] k3s[872]: I1112 17:02:55.596182 872 job_controller.go:336] "Starting job controller"1510machine # [ 29.063713] k3s[872]: I1112 17:02:55.596204 872 shared_informer.go:402] "Waiting for caches to sync"1511machine # [ 29.065102] k3s[872]: I1112 17:02:55.597371 872 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-serving"1512machine # [ 29.066910] k3s[872]: I1112 17:02:55.597404 872 shared_informer.go:402] "Waiting for caches to sync"1513machine # [ 29.069266] k3s[872]: I1112 17:02:55.597438 872 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-client"1514machine # [ 29.071230] k3s[872]: I1112 17:02:55.597454 872 shared_informer.go:402] "Waiting for caches to sync"1515machine # [ 29.072729] k3s[872]: I1112 17:02:55.597478 872 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kube-apiserver-client"1516machine # [ 29.074883] k3s[872]: I1112 17:02:55.597495 872 shared_informer.go:402] "Waiting for caches to sync"1517machine # [ 29.076726] k3s[872]: I1112 17:02:55.597530 872 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"1518machine # [ 29.079867] k3s[872]: I1112 17:02:55.597838 872 device_taint_eviction.go:823] "Sending events to api server"1519machine # [ 29.082020] k3s[872]: I1112 17:02:55.597962 872 device_taint_eviction.go:1023] "Waiting" for="cache and event handler sync"1520machine # [ 29.084319] k3s[872]: I1112 17:02:55.598012 872 resource_quota_controller.go:297] "Starting resource quota controller"1521machine # [ 29.086904] k3s[872]: I1112 17:02:55.598029 872 shared_informer.go:402] "Waiting for caches to sync"1522machine # [ 29.089027] k3s[872]: I1112 17:02:55.598100 872 garbagecollector.go:141] "Starting controller" controller="garbagecollector"1523machine # [ 29.096407] k3s[872]: I1112 17:02:55.598125 872 shared_informer.go:402] "Waiting for caches to sync"1524machine # [ 29.098032] k3s[872]: I1112 17:02:55.598309 872 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"1525machine # [ 29.100979] k3s[872]: I1112 17:02:55.598439 872 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"1526machine # [ 29.108917] k3s[872]: I1112 17:02:55.598540 872 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"1527machine # [ 29.111724] k3s[872]: I1112 17:02:55.599026 872 resource_quota_monitor.go:309] "QuotaMonitor running"1528machine # [ 29.113150] k3s[872]: I1112 17:02:55.599342 872 graph_builder.go:387] "Running" component="GraphBuilder"1529machine # [ 29.114509] k3s[872]: I1112 17:02:55.608599 872 shared_informer.go:402] "Waiting for caches to sync"1530machine # [ 29.115835] k3s[872]: I1112 17:02:55.618809 872 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceSlice + event handler k8s.io/kubernetes/pkg/controller/devicetainteviction.(*Controller).Run"1531machine # [ 29.119702] k3s[872]: I1112 17:02:55.618900 872 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceSlice"1532machine # [ 29.127409] k3s[872]: I1112 17:02:55.668631 872 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.DeviceClass"1533machine # [ 29.130254] k3s[872]: I1112 17:02:55.673560 872 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceClaim"1534machine # [ 29.132986] k3s[872]: I1112 17:02:55.673593 872 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceClaim + event handler k8s.io/kubernetes/pkg/controller/devicetainteviction.(*Controller).Run"1535machine # [ 29.136456] k3s[872]: I1112 17:02:55.673778 872 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.Pod"1536machine # [ 29.138507] k3s[872]: I1112 17:02:55.673795 872 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.Pod + event handler k8s.io/kubernetes/pkg/controller/devicetainteviction.(*Controller).Run"1537machine # [ 29.141683] k3s[872]: I1112 17:02:55.681359 872 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"1538machine # [ 29.145304] k3s[872]: I1112 17:02:55.686667 872 shared_informer.go:409] "Caches are synced"1539machine # [ 29.146508] k3s[872]: I1112 17:02:55.686788 872 node_lifecycle_controller.go:1217] "Initializing eviction metric for zone" zone=""1540machine # [ 29.148207] k3s[872]: I1112 17:02:55.686902 872 node_lifecycle_controller.go:869] "Missing timestamp for Node. Assuming now as a timestamp" node="machine"1541machine # [ 29.150078] k3s[872]: I1112 17:02:55.686970 872 node_lifecycle_controller.go:1063] "Controller detected that zone is now in new state" zone="" newState="Normal"1542machine # [ 29.152140] k3s[872]: I1112 17:02:55.692977 872 shared_informer.go:409] "Caches are synced"1543machine # [ 29.153325] k3s[872]: I1112 17:02:55.693036 872 shared_informer.go:409] "Caches are synced"1544machine # [ 29.154498] k3s[872]: I1112 17:02:55.693219 872 shared_informer.go:409] "Caches are synced"1545machine # [ 29.155711] k3s[872]: I1112 17:02:55.693263 872 shared_informer.go:409] "Caches are synced"1546machine # [ 29.156982] k3s[872]: I1112 17:02:55.693530 872 shared_informer.go:409] "Caches are synced"1547machine # [ 29.158180] k3s[872]: I1112 17:02:55.693855 872 shared_informer.go:409] "Caches are synced"1548machine # [ 29.159432] k3s[872]: I1112 17:02:55.693887 872 shared_informer.go:409] "Caches are synced"1549machine # [ 29.160672] k3s[872]: I1112 17:02:55.694070 872 shared_informer.go:409] "Caches are synced"1550machine # [ 29.161843] k3s[872]: I1112 17:02:55.694278 872 shared_informer.go:409] "Caches are synced"1551machine # [ 29.163009] k3s[872]: I1112 17:02:55.694308 872 shared_informer.go:409] "Caches are synced"1552machine # [ 29.164170] k3s[872]: I1112 17:02:55.694355 872 shared_informer.go:409] "Caches are synced"1553machine # [ 29.165344] k3s[872]: I1112 17:02:55.694381 872 shared_informer.go:409] "Caches are synced"1554machine # [ 29.167486] k3s[872]: I1112 17:02:55.694419 872 shared_informer.go:409] "Caches are synced"1555machine # [ 29.169232] k3s[872]: I1112 17:02:55.694475 872 shared_informer.go:409] "Caches are synced"1556machine # [ 29.170720] k3s[872]: I1112 17:02:55.694560 872 shared_informer.go:409] "Caches are synced"1557machine # [ 29.173267] k3s[872]: I1112 17:02:55.694710 872 shared_informer.go:409] "Caches are synced"1558machine # [ 29.174940] k3s[872]: I1112 17:02:55.694864 872 shared_informer.go:409] "Caches are synced"1559machine # [ 29.176420] k3s[872]: I1112 17:02:55.694982 872 shared_informer.go:409] "Caches are synced"1560machine # [ 29.177766] k3s[872]: I1112 17:02:55.695013 872 shared_informer.go:409] "Caches are synced"1561machine # [ 29.179106] k3s[872]: I1112 17:02:55.695124 872 shared_informer.go:409] "Caches are synced"1562machine # [ 29.180483] k3s[872]: I1112 17:02:55.695225 872 shared_informer.go:409] "Caches are synced"1563machine # [ 29.181796] k3s[872]: I1112 17:02:55.695293 872 range_allocator.go:177] "Sending events to api server"1564machine # [ 29.183189] k3s[872]: I1112 17:02:55.695323 872 range_allocator.go:181] "Starting range CIDR allocator"1565machine # [ 29.184665] k3s[872]: I1112 17:02:55.695337 872 shared_informer.go:402] "Waiting for caches to sync"1566machine # [ 29.186039] k3s[872]: I1112 17:02:55.695350 872 shared_informer.go:409] "Caches are synced"1567machine # [ 29.187336] k3s[872]: I1112 17:02:55.695665 872 shared_informer.go:409] "Caches are synced"1568machine # [ 29.188649] k3s[872]: I1112 17:02:55.695698 872 shared_informer.go:409] "Caches are synced"1569machine # [ 29.189975] k3s[872]: I1112 17:02:55.695722 872 shared_informer.go:409] "Caches are synced"1570machine # [ 29.191329] k3s[872]: I1112 17:02:55.695804 872 shared_informer.go:409] "Caches are synced"1571machine # [ 29.192688] k3s[872]: I1112 17:02:55.695855 872 shared_informer.go:409] "Caches are synced"1572machine # [ 29.194021] k3s[872]: I1112 17:02:55.695883 872 shared_informer.go:409] "Caches are synced"1573machine # [ 29.195379] k3s[872]: I1112 17:02:55.696553 872 shared_informer.go:409] "Caches are synced"1574machine # [ 29.196747] k3s[872]: I1112 17:02:55.700906 872 shared_informer.go:409] "Caches are synced"1575machine # [ 29.198043] k3s[872]: I1112 17:02:55.700965 872 shared_informer.go:409] "Caches are synced"1576machine # [ 29.199394] k3s[872]: I1112 17:02:55.702080 872 shared_informer.go:409] "Caches are synced"1577machine # [ 29.200752] k3s[872]: I1112 17:02:55.702131 872 shared_informer.go:409] "Caches are synced"1578machine # [ 29.202082] k3s[872]: I1112 17:02:55.705213 872 shared_informer.go:409] "Caches are synced"1579machine # [ 29.203378] k3s[872]: I1112 17:02:55.705267 872 shared_informer.go:409] "Caches are synced"1580machine # [ 29.204698] k3s[872]: I1112 17:02:55.705701 872 shared_informer.go:409] "Caches are synced"1581machine # [ 29.205984] k3s[872]: I1112 17:02:55.706237 872 shared_informer.go:409] "Caches are synced"1582machine # [ 29.207507] k3s[872]: I1112 17:02:55.706288 872 shared_informer.go:409] "Caches are synced"1583machine # [ 29.209165] k3s[872]: I1112 17:02:55.706320 872 shared_informer.go:409] "Caches are synced"1584machine # [ 29.211540] k3s[872]: I1112 17:02:55.706371 872 shared_informer.go:409] "Caches are synced"1585machine # [ 29.212992] k3s[872]: I1112 17:02:55.707186 872 shared_informer.go:409] "Caches are synced"1586machine # [ 29.214328] k3s[872]: I1112 17:02:55.713311 872 shared_informer.go:409] "Caches are synced"1587machine # [ 29.215679] k3s[872]: time="2026-11-12T17:02:55Z" level=info msg="Flannel found PodCIDR assigned for node machine"1588machine # [ 29.217462] k3s[872]: I1112 17:02:55.754611 872 range_allocator.go:433] "Set node PodCIDR" node="machine" podCIDRs=["10.42.0.0/24"]1589machine # [ 29.219649] k3s[872]: time="2026-11-12T17:02:55Z" level=info msg="The interface eth0 with ipv4 address 10.0.2.15 will be used by flannel"1590machine # [ 29.224318] k3s[872]: I1112 17:02:55.772995 872 kube.go:139] Waiting 10m0s for node controller to sync1591machine # [ 29.226590] k3s[872]: I1112 17:02:55.773050 872 kube.go:537] Starting kube subnet manager1592machine # [ 29.229438] k3s[872]: I1112 17:02:55.818602 872 shared_informer.go:402] "Waiting for caches to sync"1593machine # [ 29.298626] k3s[872]: time="2026-11-12T17:02:55Z" level=info msg="Event occurred" apiVersion= fieldPath= kind=Node logger=k3s message="Deferred node password secret validation complete" object=machine reason=NodePasswordValidationComplete type=Normal1594machine # Error from server (NotFound): namespaces "niks3" not found1595machine # [ 29.658660] k3s[872]: I1112 17:02:56.338986 872 controller.go:667] quota admission added evaluator for: replicasets.apps1596machine # [ 29.772880] k3s[872]: time="2026-11-12T17:02:56Z" level=info msg="Adding node OwnerReference to node-password secret machine.node-password.k3s"1597machine # [ 29.823793] k3s[872]: I1112 17:02:56.504272 872 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161598machine # [ 29.832147] k3s[872]: I1112 17:02:56.511635 872 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161599machine # [ 29.962417] k3s[872]: time="2026-11-12T17:02:56Z" 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=Normal1600machine # [ 30.072918] systemd[1]: Created slice libcontainer container kubepods-burstable-poda2c755b0_d59e_43af_a327_0e689df2518f.slice.1601machine # [ 30.093158] k3s[872]: I1112 17:02:56.773712 872 kube.go:163] Node controller sync successful1602machine # [ 30.094811] k3s[872]: I1112 17:02:56.773839 872 vxlan.go:128] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false1603machine # [ 30.100123] k3s[872]: I1112 17:02:56.779997 872 kube.go:704] List of node(machine) annotations: map[string]string{"alpha.kubernetes.io/provided-node-ip":"10.0.2.15,fec0::e927:9041:2fbc:de71", "k3s.io/hostname":"machine", "k3s.io/internal-ip":"10.0.2.15,fec0::e927:9041:2fbc:de71", "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"}1604machine # [ 30.155634] (udev-worker)[1175]: Network interface NamePolicy= disabled on kernel command line.1605machine # [ 30.194269] k3s[872]: I1112 17:02:56.868495 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-config\") pod \"helm-install-niks3-jm55s\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") " pod="kube-system/helm-install-niks3-jm55s"1606machine # [ 30.207767] systemd[1]: Created slice libcontainer container kubepods-burstable-pod38061751_a3bb_4f6a_bb92_a8ca072fd9fc.slice.1607machine # [ 30.214396] k3s[872]: I1112 17:02:56.894892 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-tmp\") pod \"helm-install-niks3-jm55s\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") " pod="kube-system/helm-install-niks3-jm55s"1608machine # [ 30.224233] k3s[872]: I1112 17:02:56.900730 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"values\" (UniqueName: \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-values\") pod \"helm-install-niks3-jm55s\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") " pod="kube-system/helm-install-niks3-jm55s"1609machine # [ 30.229922] k3s[872]: I1112 17:02:56.901153 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"content\" (UniqueName: \"kubernetes.io/configmap/a2c755b0-d59e-43af-a327-0e689df2518f-content\") pod \"helm-install-niks3-jm55s\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") " pod="kube-system/helm-install-niks3-jm55s"1610machine # [ 30.236951] k3s[872]: I1112 17:02:56.901871 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-82szx\" (UniqueName: \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-kube-api-access-82szx\") pod \"helm-install-niks3-jm55s\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") " pod="kube-system/helm-install-niks3-jm55s"1611machine # [ 30.245211] k3s[872]: I1112 17:02:56.902059 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-helm\") pod \"helm-install-niks3-jm55s\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") " pod="kube-system/helm-install-niks3-jm55s"1612machine # [ 30.252774] k3s[872]: I1112 17:02:56.909742 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-cache\") pod \"helm-install-niks3-jm55s\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") " pod="kube-system/helm-install-niks3-jm55s"1613machine # [ 30.258876] k3s[872]: I1112 17:02:56.872865 872 iptables.go:50] Starting flannel in iptables mode...1614machine # [ 30.262395] k3s[872]: time="2026-11-12T17:02:56Z" level=warning msg="no subnet found for key: FLANNEL_NETWORK in file: /run/flannel/subnet.env"1615machine # [ 30.265303] k3s[872]: time="2026-11-12T17:02:56Z" level=warning msg="no subnet found for key: FLANNEL_SUBNET in file: /run/flannel/subnet.env"1616machine # [ 30.267347] k3s[872]: time="2026-11-12T17:02:56Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_NETWORK in file: /run/flannel/subnet.env"1617machine # [ 30.270263] k3s[872]: time="2026-11-12T17:02:56Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_SUBNET in file: /run/flannel/subnet.env"1618machine # [ 30.272871] k3s[872]: I1112 17:02:56.916191 872 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 rules1619machine # [ 30.275938] k3s[872]: I1112 17:02:56.873610 872 kube.go:558] Creating the node lease for IPv4. This is the n.Spec.PodCIDRs: [10.42.0.0/24]1620machine # [ 30.296876] dhcpcd[638]: flannel.1: waiting for carrier1621machine # [ 30.298024] dhcpcd[638]: flannel.1: carrier acquired1622machine # [ 30.306650] dhcpcd[638]: flannel.1: IAID f2:1e:a1:4c1623machine # [ 30.307758] dhcpcd[638]: flannel.1: adding address fe80::878:f2ff:fe1e:a14c1624machine # [ 30.318851] k3s[872]: I1112 17:02:56.999360 872 shared_informer.go:409] "Caches are synced"1625machine # [ 30.320735] k3s[872]: I1112 17:02:56.999441 872 garbagecollector.go:166] "Garbage collector: all resource monitors have synced"1626machine # [ 30.322600] k3s[872]: I1112 17:02:56.999450 872 garbagecollector.go:169] "Proceeding to collect garbage"1627machine # [ 30.331396] k3s[872]: I1112 17:02:57.011824 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-9gp9q\" (UniqueName: \"kubernetes.io/projected/38061751-a3bb-4f6a-bb92-a8ca072fd9fc-kube-api-access-9gp9q\") pod \"coredns-7cfb7bc9c7-rqlc8\" (UID: \"38061751-a3bb-4f6a-bb92-a8ca072fd9fc\") " pod="kube-system/coredns-7cfb7bc9c7-rqlc8"1628machine # [ 30.338662] k3s[872]: I1112 17:02:57.012075 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"config-volume\" (UniqueName: \"kubernetes.io/configmap/38061751-a3bb-4f6a-bb92-a8ca072fd9fc-config-volume\") pod \"coredns-7cfb7bc9c7-rqlc8\" (UID: \"38061751-a3bb-4f6a-bb92-a8ca072fd9fc\") " pod="kube-system/coredns-7cfb7bc9c7-rqlc8"1629machine # [ 30.345091] k3s[872]: I1112 17:02:57.012113 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"custom-config-volume\" (UniqueName: \"kubernetes.io/configmap/38061751-a3bb-4f6a-bb92-a8ca072fd9fc-custom-config-volume\") pod \"coredns-7cfb7bc9c7-rqlc8\" (UID: \"38061751-a3bb-4f6a-bb92-a8ca072fd9fc\") " pod="kube-system/coredns-7cfb7bc9c7-rqlc8"1630machine # [ 30.353070] k3s[872]: I1112 17:02:57.025054 872 shared_informer.go:409] "Caches are synced"1631machine # [ 30.355318] k3s[872]: I1112 17:02:57.031895 872 iptables.go:111] Setting up masking rules1632machine # [ 30.393944] k3s[872]: I1112 17:02:57.074487 872 iptables.go:212] Changing default FORWARD chain policy to ACCEPT1633machine # [ 30.413669] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Wrote flannel subnet file to /run/flannel/subnet.env"1634machine # [ 30.416159] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Running flannel backend"1635machine # [ 30.417933] k3s[872]: I1112 17:02:57.094980 872 vxlan_network.go:68] watching for new subnet leases1636machine # [ 30.420993] k3s[872]: I1112 17:02:57.095066 872 vxlan_network.go:115] starting vxlan device watcher1637machine # [ 30.596209] cni0: port 1(veth75465c6d) entered blocking state1638machine # [ 30.596269] cni0: port 1(veth75465c6d) entered disabled state1639machine # [ 30.596313] veth75465c6d: entered allmulticast mode1640machine # [ 30.596448] veth75465c6d: entered promiscuous mode1641machine # [ 30.596986] (udev-worker)[1199]: Network interface NamePolicy= disabled on kernel command line.1642machine # [ 30.638337] k3s[872]: I1112 17:02:57.318795 872 iptables.go:358] bootstrap done1643machine # [ 30.656875] cni0: port 1(veth75465c6d) entered blocking state1644machine # [ 30.656911] cni0: port 1(veth75465c6d) entered forwarding state1645machine # [ 30.702912] dhcpcd[638]: veth75465c6d: IAID cc:76:79:361646machine # [ 30.704331] dhcpcd[638]: veth75465c6d: adding address fe80::d01a:ccff:fe76:79361647machine # [ 30.727087] cni0: port 2(vethb31bfd2d) entered blocking state1648machine # [ 30.727121] cni0: port 2(vethb31bfd2d) entered disabled state1649machine # [ 30.727160] vethb31bfd2d: entered allmulticast mode1650machine # [ 30.727295] vethb31bfd2d: entered promiscuous mode1651machine # [ 30.785142] cni0: port 2(vethb31bfd2d) entered blocking state1652machine # [ 30.785179] cni0: port 2(vethb31bfd2d) entered forwarding state1653machine # [ 30.863391] dhcpcd[638]: vethb31bfd2d: waiting for carrier1654machine # [ 30.866982] dhcpcd[638]: vethb31bfd2d: carrier acquired1655machine # [ 30.880774] dhcpcd[638]: vethb31bfd2d: IAID dd:66:fc:801656machine # [ 30.882153] dhcpcd[638]: vethb31bfd2d: adding address fe80::78ec:ddff:fe66:fc801657machine # [ 30.898549] k3s[872]: I1112 17:02:57.579069 872 iptables.go:358] bootstrap done1658machine # Error from server (NotFound): namespaces "niks3" not found1659machine # [ 31.048808] systemd[1]: Started libcontainer container bdefa0c90473a759bf701be8ba9d0708ad7053c4c436c8be13b95efffd85b738.1660machine # [ 31.056602] systemd[1]: Started libcontainer container bf3b1d644d2acb74a1364e6d6a860d9e6e32efaaa6909ab4f4e0558af8c6da51.1661machine # [ 31.136267] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Started tunnel to 10.0.2.15:6443"1662machine # [ 31.137842] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Stopped tunnel to 127.0.0.1:6443"1663machine # [ 31.141616] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Connecting to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1664machine # [ 31.144952] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"1665machine # [ 31.148556] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"1666machine # [ 31.153171] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Handling backend connection request [machine]"1667machine # [ 31.155828] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1668machine # [ 31.158116] k3s[872]: time="2026-11-12T17:02:57Z" level=info msg="Remotedialer connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1669machine # [ 31.565308] dhcpcd[638]: vethb31bfd2d: soliciting a DHCP lease1670machine # [ 31.705890] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount1685043335.mount: Deactivated successfully.1671machine # [ 31.917489] dhcpcd[638]: flannel.1: soliciting an IPv6 router1672machine # [ 31.949229] dhcpcd[638]: flannel.1: soliciting a DHCP lease1673machine # [ 32.177640] dhcpcd[638]: veth75465c6d: soliciting an IPv6 router1674machine # Error from server (NotFound): namespaces "niks3" not found1675machine # [ 32.614708] dhcpcd[638]: veth75465c6d: soliciting a DHCP lease1676machine # [ 32.749020] systemd[1]: Started libcontainer container 299f0ec7b41348600416a46b632f532bffceee0027c19c7f803c398dd420a922.1677machine # [ 33.192621] systemd[1]: Started libcontainer container 8bfe550099bd17da15b78a6066a1d29be9dd3bea44fe2ef9d324a8ba8f5f08f2.1678machine # [ 33.355763] k3s[872]: I1112 17:03:00.034361 872 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/helm-install-niks3-jm55s" podStartSLOduration=4.03433458 podStartE2EDuration="4.03433458s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 17:02:56 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 17:03:00.02937038 +0000 UTC m=+15.960824541" watchObservedRunningTime="2026-11-12 17:03:00.03433458 +0000 UTC m=+15.965788721"1679machine # [ 33.366306] k3s[872]: I1112 17:03:00.043764 872 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/coredns-7cfb7bc9c7-rqlc8" podStartSLOduration=4.04373728 podStartE2EDuration="4.04373728s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 17:02:56 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 17:02:59.5368681 +0000 UTC m=+15.468322261" watchObservedRunningTime="2026-11-12 17:03:00.04373728 +0000 UTC m=+15.975191421"1680machine # [ 33.390243] dhcpcd[638]: vethb31bfd2d: soliciting an IPv6 router1681machine # Error from server (NotFound): namespaces "niks3" not found1682machine # [ 34.192598] k3s[872]: I1112 17:03:00.873168 872 alloc.go:329] "allocated clusterIPs" service="niks3/niks3" clusterIPs={"IPv4":"10.43.21.49"}1683machine # [ 34.221556] k3s[872]: I1112 17:03:00.901700 872 controller.go:667] quota admission added evaluator for: cronjobs.batch1684machine # [ 34.273739] k3s[872]: I1112 17:03:00.954216 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-jvfqq\" (UniqueName: \"kubernetes.io/projected/8dff5aaf-8e1c-48f1-a126-e805813f1928-kube-api-access-jvfqq\") pod \"niks3-688c9f4967-rcm6g\" (UID: \"8dff5aaf-8e1c-48f1-a126-e805813f1928\") " pod="niks3/niks3-688c9f4967-rcm6g"1685machine # [ 34.282574] k3s[872]: I1112 17:03:00.954318 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"db\" (UniqueName: \"kubernetes.io/secret/8dff5aaf-8e1c-48f1-a126-e805813f1928-db\") pod \"niks3-688c9f4967-rcm6g\" (UID: \"8dff5aaf-8e1c-48f1-a126-e805813f1928\") " pod="niks3/niks3-688c9f4967-rcm6g"1686machine # [ 34.288253] k3s[872]: I1112 17:03:00.954589 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/8dff5aaf-8e1c-48f1-a126-e805813f1928-token\") pod \"niks3-688c9f4967-rcm6g\" (UID: \"8dff5aaf-8e1c-48f1-a126-e805813f1928\") " pod="niks3/niks3-688c9f4967-rcm6g"1687machine # [ 34.304072] k3s[872]: I1112 17:03:00.954619 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"s3\" (UniqueName: \"kubernetes.io/secret/8dff5aaf-8e1c-48f1-a126-e805813f1928-s3\") pod \"niks3-688c9f4967-rcm6g\" (UID: \"8dff5aaf-8e1c-48f1-a126-e805813f1928\") " pod="niks3/niks3-688c9f4967-rcm6g"1688machine # [ 34.310787] k3s[872]: I1112 17:03:00.954646 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"oidc\" (UniqueName: \"kubernetes.io/configmap/8dff5aaf-8e1c-48f1-a126-e805813f1928-oidc\") pod \"niks3-688c9f4967-rcm6g\" (UID: \"8dff5aaf-8e1c-48f1-a126-e805813f1928\") " pod="niks3/niks3-688c9f4967-rcm6g"1689machine # [ 34.320696] systemd[1]: cri-containerd-8bfe550099bd17da15b78a6066a1d29be9dd3bea44fe2ef9d324a8ba8f5f08f2.scope: Deactivated successfully.1690machine # [ 34.322433] systemd[1]: cri-containerd-8bfe550099bd17da15b78a6066a1d29be9dd3bea44fe2ef9d324a8ba8f5f08f2.scope: Consumed 869ms CPU time over 1.087s wall clock time, 36.5M memory peak, 4.5M incoming IP traffic, 93.2K outgoing IP traffic.1691machine # [ 34.327687] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod8dff5aaf_8e1c_48f1_a126_e805813f1928.slice.1692machine # [ 34.367486] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-8bfe550099bd17da15b78a6066a1d29be9dd3bea44fe2ef9d324a8ba8f5f08f2-rootfs.mount: Deactivated successfully.1693machine # [ 34.699764] cni0: port 3(veth5ddf58ca) entered blocking state1694machine # [ 34.699883] cni0: port 3(veth5ddf58ca) entered disabled state1695machine # [ 34.699922] veth5ddf58ca: entered allmulticast mode1696machine # [ 34.700047] veth5ddf58ca: entered promiscuous mode1697machine # [ 34.703179] (udev-worker)[1466]: Network interface NamePolicy= disabled on kernel command line.1698machine # [ 34.732438] cni0: port 3(veth5ddf58ca) entered blocking state1699machine # [ 34.732471] cni0: port 3(veth5ddf58ca) entered forwarding state1700machine # [ 34.770102] dhcpcd[638]: veth5ddf58ca: IAID fe:3e:44:cc1701machine # [ 34.771130] dhcpcd[638]: veth5ddf58ca: adding address fe80::2cb7:feff:fe3e:44cc1702machine # [ 34.932761] systemd[1]: Started libcontainer container 6572b177cb0658053e49e44c3de7daa8d3807fcca719347675f8d732dd96a35c.1703machine # [ 35.425470] systemd[1]: Started libcontainer container c860d1b638f76a00796b5dac8a82532b1396c4312600884381e311a778085d84.1704machine # [ 36.435372] systemd[1]: cri-containerd-bf3b1d644d2acb74a1364e6d6a860d9e6e32efaaa6909ab4f4e0558af8c6da51.scope: Deactivated successfully.1705machine # [ 36.508279] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-bf3b1d644d2acb74a1364e6d6a860d9e6e32efaaa6909ab4f4e0558af8c6da51-rootfs.mount: Deactivated successfully.1706machine # [ 36.566537] dhcpcd[638]: vethb31bfd2d: probing for an IPv4LL address1707machine # [ 36.580416] k3s[872]: I1112 17:03:03.259324 872 kuberuntime_manager.go:2172] "Updating runtime config through cri with podcidr" CIDR="10.42.0.0/24"1708machine # [ 36.583672] k3s[872]: I1112 17:03:03.260989 872 kubelet_network.go:48] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="10.42.0.0/24"1709machine # [ 36.640242] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-bf3b1d644d2acb74a1364e6d6a860d9e6e32efaaa6909ab4f4e0558af8c6da51-shm.mount: Deactivated successfully.1710machine # [ 36.652199] dhcpcd[638]: veth5ddf58ca: soliciting a DHCP lease1711machine # [ 36.706509] dhcpcd[638]: veth75465c6d: carrier lost[ 36.710668] cni0: port 1(veth75465c6d) entered disabled state1712machine # 1713machine # [ 36.712480] veth75465c6d (unregistering): left allmulticast mode1714machine # [ 36.712512] veth75465c6d (unregistering): left promiscuous mode1715machine # [ 36.712530] cni0: port 1(veth75465c6d) entered disabled state1716machine # [ 36.742167] systemd[1]: run-netns-cni\x2d30bea18f\x2df267\x2d82a4\x2df1c1\x2dec9eb11b7c6d.mount: Deactivated successfully.1717machine # [ 36.765169] dhcpcd[638]: veth75465c6d: deleting address fe80::d01a:ccff:fe76:79361718machine # [ 36.820532] dhcpcd[638]: veth75465c6d: removing interface1719machine # [ 36.950415] dhcpcd[638]: flannel.1: probing for an IPv4LL address1720machine # [ 37.143284] k3s[872]: time="2026-11-12T17:03:03Z" level=info msg="Starting network policy controller version v2.6.3-k3s1, built on 1970-01-01T01:01:01Z, go1.26.10"1721machine # [ 37.146924] k3s[872]: I1112 17:03:03.823789 872 network_policy_controller.go:164] Starting network policy controller1722machine # [ 37.174556] k3s[872]: I1112 17:03:03.854739 872 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-688c9f4967-rcm6g" podStartSLOduration=3.8547041 podStartE2EDuration="3.8547041s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 17:03:00 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 17:03:02.22987476 +0000 UTC m=+18.161328921" watchObservedRunningTime="2026-11-12 17:03:03.8547041 +0000 UTC m=+19.786158481"1723machine # [ 37.197484] k3s[872]: I1112 17:03:03.878040 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-config\") pod \"a2c755b0-d59e-43af-a327-0e689df2518f\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") "1724machine # [ 37.205272] k3s[872]: I1112 17:03:03.878108 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-values\" (UniqueName: \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-values\") pod \"a2c755b0-d59e-43af-a327-0e689df2518f\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") "1725machine # [ 37.212480] k3s[872]: I1112 17:03:03.878144 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-helm\") pod \"a2c755b0-d59e-43af-a327-0e689df2518f\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") "1726machine # [ 37.218907] k3s[872]: I1112 17:03:03.878185 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-cache\") pod \"a2c755b0-d59e-43af-a327-0e689df2518f\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") "1727machine # [ 37.225332] k3s[872]: I1112 17:03:03.878218 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/configmap/a2c755b0-d59e-43af-a327-0e689df2518f-content\" (UniqueName: \"kubernetes.io/configmap/a2c755b0-d59e-43af-a327-0e689df2518f-content\") pod \"a2c755b0-d59e-43af-a327-0e689df2518f\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") "1728machine # [ 37.231086] k3s[872]: I1112 17:03:03.878247 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-tmp\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-tmp\") pod \"a2c755b0-d59e-43af-a327-0e689df2518f\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") "1729machine # [ 37.236541] k3s[872]: I1112 17:03:03.878276 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-kube-api-access-82szx\" (UniqueName: \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-kube-api-access-82szx\") pod \"a2c755b0-d59e-43af-a327-0e689df2518f\" (UID: \"a2c755b0-d59e-43af-a327-0e689df2518f\") "1730machine # [ 37.242666] systemd[1]: var-lib-kubelet-pods-a2c755b0\x2dd59e\x2d43af\x2da327\x2d0e689df2518f-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dconfig.mount: Deactivated successfully.1731machine # [ 37.247277] k3s[872]: I1112 17:03:03.920411 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/configmap/a2c755b0-d59e-43af-a327-0e689df2518f-content" pod "a2c755b0-d59e-43af-a327-0e689df2518f" (UID: "a2c755b0-d59e-43af-a327-0e689df2518f"). InnerVolumeSpecName "content". PluginName "kubernetes.io/configmap", VolumeGIDValue ""1732machine # [ 37.253567] k3s[872]: I1112 17:03:03.920644 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-config" pod "a2c755b0-d59e-43af-a327-0e689df2518f" (UID: "a2c755b0-d59e-43af-a327-0e689df2518f"). InnerVolumeSpecName "klipper-config". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1733machine # [ 37.258612] k3s[872]: I1112 17:03:03.922118 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-values" pod "a2c755b0-d59e-43af-a327-0e689df2518f" (UID: "a2c755b0-d59e-43af-a327-0e689df2518f"). InnerVolumeSpecName "values". PluginName "kubernetes.io/projected", VolumeGIDValue ""1734machine # [ 37.263159] k3s[872]: I1112 17:03:03.922272 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-helm" pod "a2c755b0-d59e-43af-a327-0e689df2518f" (UID: "a2c755b0-d59e-43af-a327-0e689df2518f"). InnerVolumeSpecName "klipper-helm". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1735machine # [ 37.267807] systemd[1]: var-lib-kubelet-pods-a2c755b0\x2dd59e\x2d43af\x2da327\x2d0e689df2518f-volumes-kubernetes.io\x7eprojected-values.mount: Deactivated successfully.1736machine # [ 37.270038] k3s[872]: I1112 17:03:03.935207 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-kube-api-access-82szx" pod "a2c755b0-d59e-43af-a327-0e689df2518f" (UID: "a2c755b0-d59e-43af-a327-0e689df2518f"). InnerVolumeSpecName "kube-api-access-82szx". PluginName "kubernetes.io/projected", VolumeGIDValue ""1737machine # [ 37.274883] k3s[872]: I1112 17:03:03.936587 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-tmp" pod "a2c755b0-d59e-43af-a327-0e689df2518f" (UID: "a2c755b0-d59e-43af-a327-0e689df2518f"). InnerVolumeSpecName "tmp". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1738machine # [ 37.279365] k3s[872]: I1112 17:03:03.943635 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-cache" pod "a2c755b0-d59e-43af-a327-0e689df2518f" (UID: "a2c755b0-d59e-43af-a327-0e689df2518f"). InnerVolumeSpecName "klipper-cache". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1739machine # [ 37.298630] k3s[872]: I1112 17:03:03.979177 872 reconciler_common.go:299] "Volume detached for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-config\") on node \"machine\" DevicePath \"\""1740machine # [ 37.301856] k3s[872]: I1112 17:03:03.979213 872 reconciler_common.go:299] "Volume detached for volume \"values\" (UniqueName: \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-values\") on node \"machine\" DevicePath \"\""1741machine # [ 37.304868] k3s[872]: I1112 17:03:03.979230 872 reconciler_common.go:299] "Volume detached for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-helm\") on node \"machine\" DevicePath \"\""1742machine # [ 37.307805] k3s[872]: I1112 17:03:03.979239 872 reconciler_common.go:299] "Volume detached for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-klipper-cache\") on node \"machine\" DevicePath \"\""1743machine # [ 37.311030] k3s[872]: I1112 17:03:03.979249 872 reconciler_common.go:299] "Volume detached for volume \"content\" (UniqueName: \"kubernetes.io/configmap/a2c755b0-d59e-43af-a327-0e689df2518f-content\") on node \"machine\" DevicePath \"\""1744machine # [ 37.313912] k3s[872]: I1112 17:03:03.979259 872 reconciler_common.go:299] "Volume detached for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/a2c755b0-d59e-43af-a327-0e689df2518f-tmp\") on node \"machine\" DevicePath \"\""1745machine # [ 37.316703] k3s[872]: I1112 17:03:03.979274 872 reconciler_common.go:299] "Volume detached for volume \"kube-api-access-82szx\" (UniqueName: \"kubernetes.io/projected/a2c755b0-d59e-43af-a327-0e689df2518f-kube-api-access-82szx\") on node \"machine\" DevicePath \"\""1746machine # [ 37.376736] k3s[872]: I1112 17:03:04.057290 872 network_policy_controller.go:179] Starting network policy controller full sync goroutine1747machine # [ 37.416545] k3s[872]: I1112 17:03:04.097026 872 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="bf3b1d644d2acb74a1364e6d6a860d9e6e32efaaa6909ab4f4e0558af8c6da51"1748machine # [ 37.427208] systemd[1]: Removed slice libcontainer container kubepods-burstable-poda2c755b0_d59e_43af_a327_0e689df2518f.slice.1749machine # [ 37.430390] systemd[1]: kubepods-burstable-poda2c755b0_d59e_43af_a327_0e689df2518f.slice: Consumed 912ms CPU time over 7.354s wall clock time, 36.7M memory peak, 4.5M incoming IP traffic, 93.2K outgoing IP traffic.1750machine # [ 37.438140] dhcpcd[638]: veth5ddf58ca: soliciting an IPv6 router1751machine # [ 37.504742] systemd[1]: var-lib-kubelet-pods-a2c755b0\x2dd59e\x2d43af\x2da327\x2d0e689df2518f-volumes-kubernetes.io\x7eprojected-kube\x2dapi\x2daccess\x2d82szx.mount: Deactivated successfully.1752machine # [ 37.512366] systemd[1]: var-lib-kubelet-pods-a2c755b0\x2dd59e\x2d43af\x2da327\x2d0e689df2518f-volumes-kubernetes.io\x7eempty\x2ddir-tmp.mount: Deactivated successfully.1753machine # [ 37.514480] systemd[1]: var-lib-kubelet-pods-a2c755b0\x2dd59e\x2d43af\x2da327\x2d0e689df2518f-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dcache.mount: Deactivated successfully.1754machine # [ 37.519513] systemd[1]: var-lib-kubelet-pods-a2c755b0\x2dd59e\x2d43af\x2da327\x2d0e689df2518f-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dhelm.mount: Deactivated successfully.1755machine # [ 41.173698] dhcpcd[638]: vethb31bfd2d: using IPv4LL address 169.254.83.1831756machine # [ 41.174069] dhcpcd[638]: vethb31bfd2d: adding route to 169.254.0.0/161757[42.26s] machine: (finished: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s, in 16.39 seconds)1758[42.26s] machine: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true1759machine # [ 41.651495] dhcpcd[638]: veth5ddf58ca: probing for an IPv4LL address1760machine # [ 41.751761] dhcpcd[638]: flannel.1: using IPv4LL address 169.254.48.1391761machine # [ 41.755585] dhcpcd[638]: flannel.1: adding route to 169.254.0.0/161762[42.55s] machine: (finished: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true, in 0.29 seconds)1763[42.55s] machine: waiting for success: curl -sf http://localhost:30051/readyz | grep OK1764[42.60s] machine: (finished: waiting for success: curl -sf http://localhost:30051/readyz | grep OK, in 0.05 seconds)1765[42.60s] (finished: subtest: chart deploys and becomes ready, in 16.73 seconds)1766[42.60s] machine: waiting for success: kubectl -n ci get sa builder1767[42.81s] machine: (finished: waiting for success: kubectl -n ci get sa builder, in 0.21 seconds)1768[42.81s] machine: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt1769[43.03s] machine: (finished: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt, in 0.22 seconds)1770[43.03s] machine: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt1771[43.21s] machine: (finished: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt, in 0.18 seconds)1772[43.21s] machine: must succeed: readlink -f /run/current-system/sw/bin/niks31773[43.23s] machine: (finished: must succeed: readlink -f /run/current-system/sw/bin/niks3, in 0.02 seconds)1774[43.23s] subtest: allowed service account can push via workload identity1775[43.23s] machine: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&11776[44.50s] machine: (finished: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&1, in 1.27 seconds)1777[44.50s] machine: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/an044afijna5agsc71nj88va0jbxiq27.narinfo1778[44.53s] machine: (finished: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/an044afijna5agsc71nj88va0jbxiq27.narinfo, in 0.03 seconds)1779[44.53s] (finished: subtest: allowed service account can push via workload identity, in 1.30 seconds)1780[44.53s] subtest: write scope does not grant admin1781[44.53s] machine: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status1782[44.56s] machine: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status, in 0.03 seconds)1783[44.56s] (finished: subtest: write scope does not grant admin, in 0.03 seconds)1784[44.56s] subtest: other service accounts are rejected1785[44.56s] machine: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&11786machine # [ 43.919791] dhcpcd[638]: flannel.1: no IPv6 Routers available1787[44.69s] machine: (finished: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 2>&1, in 0.13 seconds)1788[44.69s] (finished: subtest: other service accounts are rejected, in 0.13 seconds)1789[44.69s] subtest: gc cronjob runs against the service1790[44.69s] machine: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual1791[44.88s] machine: (finished: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual, in 0.19 seconds)1792[44.88s] machine: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s1793machine # [ 44.150577] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod1cf04679_2dc5_4ae3_bbfd_9da92d2b3df1.slice.1794machine # [ 44.170143] k3s[872]: I1112 17:03:10.849180 872 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1-token\") pod \"gc-manual-2q2c9\" (UID: \"1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1\") " pod="niks3/gc-manual-2q2c9"1795machine # [ 44.546677] (udev-worker)[1944]: Network interface NamePolicy= disabled on kernel command line.1796machine # [ 44.553612] cni0: port 1(vethc2fb19fd) entered blocking state1797machine # [ 44.553649] cni0: port 1(vethc2fb19fd) entered disabled state1798machine # [ 44.553693] vethc2fb19fd: entered allmulticast mode1799machine # [ 44.553831] vethc2fb19fd: entered promiscuous mode1800machine # [ 44.573914] cni0: port 1(vethc2fb19fd) entered blocking state1801machine # [ 44.573951] cni0: port 1(vethc2fb19fd) entered forwarding state1802machine # [ 44.610791] dhcpcd[638]: vethc2fb19fd: IAID 72:1b:8e:781803machine # [ 44.612123] dhcpcd[638]: vethc2fb19fd: adding address fe80::acc8:72ff:fe1b:8e781804machine # [ 44.708726] systemd[1]: Started libcontainer container 2658c2ac248e4312bf02a507b7a6a35ea109221614fb680e098b9abc53afc556.1805machine # [ 44.873037] systemd[1]: Started libcontainer container 683dd546c7fd36c15b1643e0ae0851a096e49b1a6628d6cb593900ad762fefb4.1806machine # [ 45.001358] k3s[872]: I1112 17:03:11.681417 872 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/gc-manual-2q2c9" podStartSLOduration=1.68138488 podStartE2EDuration="1.68138488s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 17:03:10 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 17:03:11.68110596 +0000 UTC m=+27.612560121" watchObservedRunningTime="2026-11-12 17:03:11.68138488 +0000 UTC m=+27.612839021"1807machine # [ 45.369270] dhcpcd[638]: vethb31bfd2d: no IPv6 Routers available1808machine # [ 45.845705] dhcpcd[638]: vethc2fb19fd: soliciting a DHCP lease1809machine # [ 46.502225] dhcpcd[638]: veth5ddf58ca: using IPv4LL address 169.254.29.1281810machine # [ 46.502555] dhcpcd[638]: veth5ddf58ca: adding route to 169.254.0.0/161811machine # [ 46.969358] systemd[1]: cri-containerd-683dd546c7fd36c15b1643e0ae0851a096e49b1a6628d6cb593900ad762fefb4.scope: Deactivated successfully.1812machine # [ 46.973322] systemd[1]: cri-containerd-683dd546c7fd36c15b1643e0ae0851a096e49b1a6628d6cb593900ad762fefb4.scope: Consumed 53ms CPU time over 2.096s wall clock time, 13.1M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1813machine # [ 47.024109] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-683dd546c7fd36c15b1643e0ae0851a096e49b1a6628d6cb593900ad762fefb4-rootfs.mount: Deactivated successfully.1814machine # [ 47.209138] dhcpcd[638]: vethc2fb19fd: soliciting an IPv6 router1815machine # [ 48.477477] systemd[1]: cri-containerd-2658c2ac248e4312bf02a507b7a6a35ea109221614fb680e098b9abc53afc556.scope: Deactivated successfully.1816machine # [ 48.528381] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-2658c2ac248e4312bf02a507b7a6a35ea109221614fb680e098b9abc53afc556-rootfs.mount: Deactivated successfully.1817machine # [ 48.567827] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-2658c2ac248e4312bf02a507b7a6a35ea109221614fb680e098b9abc53afc556-shm.mount: Deactivated successfully.1818machine # [ 48.620834] cni0: port 1(vethc2fb19fd) entered disabled state1819machine # [ 48.616838] dhcpcd[638]: vethc2fb19fd: carrier lost1820machine # [ 48.624432] vethc2fb19fd (unregistering): left allmulticast mode1821machine # [ 48.624458] vethc2fb19fd (unregistering): left promiscuous mode1822machine # [ 48.624473] cni0: port 1(vethc2fb19fd) entered disabled state1823machine # [ 48.651712] systemd[1]: run-netns-cni\x2dab895dec\x2dda2e\x2d0ac8\x2d02f0\x2d1911e4b2979b.mount: Deactivated successfully.1824machine # [ 48.690455] dhcpcd[638]: vethc2fb19fd: deleting address fe80::acc8:72ff:fe1b:8e781825machine # [ 48.703979] k3s[872]: I1112 17:03:15.384233 872 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/secret/1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1-token\" (UniqueName: \"kubernetes.io/secret/1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1-token\") pod \"1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1\" (UID: \"1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1\") "1826machine # [ 48.717554] systemd[1]: var-lib-kubelet-pods-1cf04679\x2d2dc5\x2d4ae3\x2dbbfd\x2d9da92d2b3df1-volumes-kubernetes.io\x7esecret-token.mount: Deactivated successfully.1827machine # [ 48.722853] k3s[872]: I1112 17:03:15.403439 872 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1-token" pod "1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1" (UID: "1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1"). InnerVolumeSpecName "token". PluginName "kubernetes.io/secret", VolumeGIDValue ""1828machine # [ 48.740743] dhcpcd[638]: vethc2fb19fd: removing interface1829machine # [ 48.803875] k3s[872]: I1112 17:03:15.484483 872 reconciler_common.go:299] "Volume detached for volume \"token\" (UniqueName: \"kubernetes.io/secret/1cf04679-2dc5-4ae3-bbfd-9da92d2b3df1-token\") on node \"machine\" DevicePath \"\""1830machine # [ 49.441386] dhcpcd[638]: veth5ddf58ca: no IPv6 Routers available1831machine # [ 49.458439] k3s[872]: I1112 17:03:16.138798 872 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="2658c2ac248e4312bf02a507b7a6a35ea109221614fb680e098b9abc53afc556"1832machine # [ 49.472712] systemd[1]: Removed slice libcontainer container kubepods-besteffort-pod1cf04679_2dc5_4ae3_bbfd_9da92d2b3df1.slice.1833machine # [ 49.475727] systemd[1]: kubepods-besteffort-pod1cf04679_2dc5_4ae3_bbfd_9da92d2b3df1.slice: Consumed 99ms CPU time over 5.321s wall clock time, 15.6M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1834[50.29s] machine: (finished: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s, in 5.41 seconds)1835[50.29s] (finished: subtest: gc cronjob runs against the service, in 5.60 seconds)1836[50.29s] subtest: helm test hook passes1837[50.29s] machine: must succeed: helm test -n niks3 niks3 --timeout 2m >&21838machine # [ 50.165335] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod7306301b_9ac1_46ee_a776_faa1a06e353f.slice.1839machine # [ 50.213317] cni0: port 1(vethd11b767b) entered blocking state1840machine # [ 50.214422] cni0: port 1(vethd11b767b) entered disabled state1841machine # [ 50.214473] vethd11b767b: entered allmulticast mode1842machine # [ 50.214607] vethd11b767b: entered promiscuous mode1843machine # [ 50.214827] (udev-worker)[2384]: Network interface NamePolicy= disabled on kernel command line.1844machine # [ 50.263172] cni0: port 1(vethd11b767b) entered blocking state1845machine # [ 50.263206] cni0: port 1(vethd11b767b) entered forwarding state1846machine # [ 50.289167] dhcpcd[638]: vethd11b767b: waiting for carrier1847machine # [ 50.290168] dhcpcd[638]: vethd11b767b: carrier acquired1848machine # [ 50.298833] dhcpcd[638]: vethd11b767b: IAID 88:59:01:c71849machine # [ 50.299849] dhcpcd[638]: vethd11b767b: adding address fe80::47:88ff:fe59:1c71850machine # [ 50.404953] systemd[1]: Started libcontainer container 2429864a32592faabb82f7e4427d87e43c0bd4f8d2c15e8f0fa4d3b796b39068.1851machine # [ 50.560615] systemd[1]: Started libcontainer container 60b8775330a8e38edfc8ffc3a2ee8f8d2a51959b944fc4d75ecfbc8704488025.1852machine # [ 50.617672] systemd[1]: cri-containerd-60b8775330a8e38edfc8ffc3a2ee8f8d2a51959b944fc4d75ecfbc8704488025.scope: Deactivated successfully.1853machine # [ 50.619495] systemd[1]: cri-containerd-60b8775330a8e38edfc8ffc3a2ee8f8d2a51959b944fc4d75ecfbc8704488025.scope: Consumed 29ms CPU time over 56ms wall clock time, 14.1M memory peak, 693B incoming IP traffic, 495B outgoing IP traffic.1854machine # [ 50.627144] dhcpcd[638]: vethd11b767b: soliciting a DHCP lease1855machine # [ 50.667757] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-60b8775330a8e38edfc8ffc3a2ee8f8d2a51959b944fc4d75ecfbc8704488025-rootfs.mount: Deactivated successfully.1856machine # [ 51.488625] dhcpcd[638]: vethd11b767b: soliciting an IPv6 router1857machine # [ 52.495664] systemd[1]: cri-containerd-2429864a32592faabb82f7e4427d87e43c0bd4f8d2c15e8f0fa4d3b796b39068.scope: Deactivated successfully.1858machine # [ 52.543875] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-2429864a32592faabb82f7e4427d87e43c0bd4f8d2c15e8f0fa4d3b796b39068-rootfs.mount: Deactivated successfully.1859machine # [ 52.579887] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-2429864a32592faabb82f7e4427d87e43c0bd4f8d2c15e8f0fa4d3b796b39068-shm.mount: Deactivated successfully.1860machine # [ 52.626881] dhcpcd[638]: vethd11b767b: carrier lost[ 52.630701] cni0: port 1(vethd11b767b) entered disabled state1861machine # [ 52.632147] vethd11b767b (unregistering): left allmulticast mode1862machine # [ 52.632188] vethd11b767b (unregistering): left promiscuous mode1863machine # [ 52.632204] cni0: port 1(vethd11b767b) entered disabled state1864machine # 1865machine # [ 52.666352] systemd[1]: run-netns-cni\x2d27212a93\x2d970d\x2d457e\x2de120\x2da10950fb1127.mount: Deactivated successfully.1866machine # [ 52.683210] dhcpcd[638]: vethd11b767b: deleting address fe80::47:88ff:fe59:1c71867machine # NAME: niks31868machine # LAST DEPLOYED: Thu Nov 12 17:03:00 20261869machine # NAMESPACE: niks31870machine # STATUS: deployed1871machine # REVISION: 11872machine # DESCRIPTION: Install complete1873machine # TEST SUITE: niks3-test1874machine # Last Started: Thu Nov 12 17:03:16 20261875machine # Last Completed: Thu Nov 12 17:03:19 20261876machine # Phase: Succeeded1877[53.50s] machine: (finished: must succeed: helm test -n niks3 niks3 --timeout 2m >&2, in 3.22 seconds)1878[53.50s] (finished: subtest: helm test hook passes, in 3.22 seconds)1879[53.50s] (finished: run the VM test script, in 53.50 seconds)1880machine # [ 52.772403] dhcpcd[638]: vethd11b767b: removing interface1881[53.54s] test script finished in 53.54s1882[53.54s] cleanup1883[53.54s] kill QemuMachine (pid 45)1884machine # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/lq2fsnmg0q3y0vlxn91w8s8wvj1m6fld-python3-3.14.8/bin/python3.14)1885machine # [2026-11-12T17:03:19Z INFO virtiofsd] Client disconnected, shutting down1886machine # [2026-11-12T17:03:19Z INFO virtiofsd] Client disconnected, shutting down1887machine # [2026-11-12T17:03:19Z INFO virtiofsd] Client disconnected, shutting down1888[54.37s] (finished: cleanup, in 0.83 seconds)1889additionally exposed symbols:1890 machine,1891 vlan1,1892 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_ssh1893time=2026-11-12T17:03:09.348Z level=INFO msg="Uploading 8 paths to localhost (0 already cached)"1894time=2026-11-12T17:03:09.348Z level=INFO msg="Uploading nhphqkv18x8fpf3flz0bsm1h554pawn7-glibc-2.44-57 (44.8MB)"1895time=2026-11-12T17:03:09.349Z level=INFO msg="Uploading vr8lx1cjz6zw4xhmb4k405v6cqrkslnk-libunistring-1.4.2 (2.0MB)"1896time=2026-11-12T17:03:09.350Z level=INFO msg="Uploading wsn07qxxn13gcdcjw5avz47j8lb2zpdv-libidn2-2.3.8 (366.1KB)"1897time=2026-11-12T17:03:09.351Z level=INFO msg="Uploading 09mqjwlgdr2jchjchwpgff2vryn4zc4q-xgcc-16.2.0-libgcc (150.2KB)"1898time=2026-11-12T17:03:09.351Z level=INFO msg="Uploading an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 (7.2MB)"1899time=2026-11-12T17:03:09.352Z level=INFO msg="Uploading ad9h5b41f7x4fvk22axfjvxykisyjc15-tzdata-2026e (2.0MB)"1900time=2026-11-12T17:03:09.352Z level=INFO msg="Uploading 7kfrkscfmm8p09q9w392p86rxqji8cbf-mailcap-2.1.54 (116.6KB)"1901time=2026-11-12T17:03:09.353Z level=INFO msg="Uploading a9l8h2d532wk9zpyvl3qms0v5iwbjp67-iana-etc-20251215 (557.8KB)"1902time=2026-11-12T17:03:10.371Z level=INFO msg="Uploading 8 narinfos"1903time=2026-11-12T17:03:10.419Z level=INFO msg="Upload complete. (1.169s)"1904