vm-test-run-nixos-test-k3s
checks.aarch64-linux.nixos-test-k3s
· build #510
· 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.00s] machine: waiting for unit k3s.service8[0.00s] machine: waiting for the VM to finish booting9[0.00s] machine: starting vm10machine # Disk image does not exist, creating the virtualisation disk image...11[0.42s] machine: QEMU running (pid 45)12machine # Formatting '/build/vm-state-machine/tmp.L9EuwEWf3N', 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: 1b4100e5-9af7-4880-b241-233448e499af17machine # 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-12T16:57:14Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)28machine # [2026-11-12T16:57:14Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether29machine # [2026-11-12T16:57:14Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)30machine # [2026-11-12T16:57:14Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether31machine # [2026-11-12T16:57:14Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)32machine # [2026-11-12T16:57:14Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether33machine # [2026-11-12T16:57:14Z INFO virtiofsd] Waiting for vhost-user socket connection...34machine # [2026-11-12T16:57:14Z INFO virtiofsd] Waiting for vhost-user socket connection...35machine # [2026-11-12T16:57:14Z INFO virtiofsd] Waiting for vhost-user socket connection...36machine # [2026-11-12T16:57:14Z INFO virtiofsd] Client connected, servicing requests37machine # [2026-11-12T16:57:14Z INFO virtiofsd] Client connected, servicing requests38machine # [2026-11-12T16:57:14Z 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/sxvg1zjz3k40v3aricf5f7yvydyjl6qf-nixos-system-machine-test/init regInfo=/nix/.ro-store/3srafd668mvkqgpwmkvq9qd3hi5xl1f4-closure-info/registration console=ttyAMA0,115200n8 console=tty074machine # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/3srafd668mvkqgpwmkvq9qd3hi5xl1f4-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 @0x0000000045520000112machine # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000045530000113machine # [ 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.000032] arm-pv: using stolen time PV119machine # [ 0.000407] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)120machine # [ 0.000629] Console: colour dummy device 80x25121machine # [ 0.000637] printk: legacy console [tty0] enabled122machine # [ 0.000824] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)123machine # [ 0.000831] pid_max: default: 32768 minimum: 301124machine # [ 0.000915] LSM: initializing lsm=lockdown,capability,landlock,yama,bpf,ima125machine # [ 0.001038] landlock: Up and running.126machine # [ 0.001041] Yama: becoming mindful.127machine # [ 0.001470] LSM support for eBPF active128machine # [ 0.001649] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)129machine # [ 0.001717] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)130machine # [ 0.003721] rcu: Hierarchical SRCU implementation.131machine # [ 0.003727] rcu: Max phase no-delay instances is 1000.132machine # [ 0.003873] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level133machine # [ 0.004999] fsl-mc MSI: its@8080000 domain created134machine # [ 0.005125] EFI services will not be available.135machine # [ 0.005230] smp: Bringing up secondary CPUs ...136machine # [ 0.005780] Detected PIPT I-cache on CPU1137machine # [ 0.005841] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000138machine # [ 0.005917] GICv3: CPU1: using allocated LPI pending table @0x0000000045540000139machine # [ 0.005991] CPU1: Booted secondary processor 0x0000000001 [0xc00fac40]140machine # [ 0.006350] smp: Brought up 1 node, 2 CPUs141machine # [ 0.006366] SMP: Total of 2 processors activated.142machine # [ 0.006368] CPU: All CPU(s) started at EL1143machine # [ 0.006377] CPU features: detected: Branch Target Identification144machine # [ 0.006380] CPU features: detected: ARMv8.4 Translation Table Level145machine # [ 0.006383] CPU features: detected: Instruction cache invalidation not required for I/D coherence146machine # [ 0.006386] CPU features: detected: Data cache clean to the PoU not required for I/D coherence147machine # [ 0.006390] CPU features: detected: Common not Private translations148machine # [ 0.006393] CPU features: detected: CRC32 instructions149machine # [ 0.006395] CPU features: detected: Data cache clean to Point of Deep Persistence150machine # [ 0.006398] CPU features: detected: Data cache clean to Point of Persistence151machine # [ 0.006401] CPU features: detected: Data independent timing control (DIT)152machine # [ 0.006404] CPU features: detected: E0PD153machine # [ 0.006407] CPU features: detected: Enhanced Counter Virtualization154machine # [ 0.006409] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)155machine # [ 0.006412] CPU features: detected: Enhanced Virtualization Traps156machine # [ 0.006415] CPU features: detected: Fine Grained Traps157machine # [ 0.006417] CPU features: detected: Generic authentication (architected QARMA5 algorithm)158machine # [ 0.006421] CPU features: detected: RCpc load-acquire (LDAPR)159machine # [ 0.006427] CPU features: detected: LSE atomic instructions160machine # [ 0.006430] CPU features: detected: Privileged Access Never161machine # [ 0.006432] CPU features: detected: PMUv3162machine # [ 0.006435] CPU features: detected: RAS Extension Support163machine # [ 0.006437] CPU features: detected: RASv1p1 Extension Support164machine # [ 0.006440] CPU features: detected: Random Number Generator165machine # [ 0.006442] CPU features: detected: Speculation barrier (SB)166machine # [ 0.006445] CPU features: detected: Stage-2 Force Write-Back167machine # [ 0.006447] CPU features: detected: TLB range maintenance instructions168machine # [ 0.006451] CPU features: detected: Speculative Store Bypassing Safe (SSBS)169machine # [ 0.006516] alternatives: applying system-wide alternatives170machine # [ 0.009498] CPU features: detected: BBM Level 2 without TLB conflict abort171machine # [ 0.009761] Memory: 2938468K/3145728K available (24640K kernel code, 10246K rwdata, 26664K rodata, 7808K init, 2086K bss, 160580K reserved, 32768K cma-reserved)172machine # [ 0.010740] devtmpfs: initialized173machine # [ 0.013240] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)174machine # [ 0.013279] futex hash table entries: 512 (32768 bytes on 1 NUMA nodes, total 32 KiB, linear).175machine # [ 0.013455] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL176machine # [ 0.013463] 0 pages in range for non-PLT usage177machine # [ 0.013464] 506368 pages in range for PLT usage178machine # [ 0.013607] pinctrl core: initialized pinctrl subsystem179machine # [ 0.014421] DMI not present or invalid.180machine # [ 0.017967] NET: Registered PF_NETLINK/PF_ROUTE protocol family181machine # [ 0.020371] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations182machine # [ 0.020657] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations183machine # [ 0.020961] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations184machine # [ 0.020985] audit: initializing netlink subsys (disabled)185machine # [ 0.021420] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1186machine # [ 0.022839] thermal_sys: Registered thermal governor 'fair_share'187machine # [ 0.022845] thermal_sys: Registered thermal governor 'bang_bang'188machine # [ 0.022854] thermal_sys: Registered thermal governor 'step_wise'189machine # [ 0.022858] thermal_sys: Registered thermal governor 'user_space'190machine # [ 0.022862] thermal_sys: Registered thermal governor 'power_allocator'191machine # [ 0.022938] cpuidle: using governor ladder192machine # [ 0.022975] cpuidle: using governor menu193machine # [ 0.023368] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.194machine # [ 0.023426] ASID allocator initialised with 65536 entries195machine # [ 0.025361] Serial: AMBA PL011 UART driver196machine # [ 0.034417] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1197machine # [ 0.034506] printk: console [ttyAMA0] enabled198machine # [ 0.202515] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages199machine # [ 0.202527] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page200machine # [ 0.202532] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages201machine # [ 0.202536] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page202machine # [ 0.202541] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages203machine # [ 0.202545] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page204machine # [ 0.202549] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages205machine # [ 0.202553] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page206machine # [ 0.213586] fbcon: Taking over console207machine # [ 0.213605] ACPI: Interpreter disabled.208machine # [ 0.215858] iommu: Default domain type: Translated209machine # [ 0.215865] iommu: DMA domain TLB invalidation policy: strict mode210machine # [ 0.221204] SCSI subsystem initialized211machine # [ 0.221557] usbcore: registered new interface driver usbfs212machine # [ 0.221602] usbcore: registered new interface driver hub213machine # [ 0.221620] usbcore: registered new device driver usb214machine # [ 0.221913] pps_core: LinuxPPS API ver. 1 registered215machine # [ 0.221917] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>216machine # [ 0.221927] PTP clock support registered217machine # [ 0.221992] EDAC MC: Ver: 3.0.0218machine # [ 0.222346] scmi_core: SCMI protocol bus registered219machine # [ 0.222995] FPGA manager framework220machine # [ 0.223904] vgaarb: loaded221machine # [ 0.224423] clocksource: Switched to clocksource arch_sys_counter222machine # [ 0.229284] VFS: Disk quotas dquot_6.6.0223machine # [ 0.229323] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)224machine # [ 0.229780] netfs: FS-Cache loaded225machine # [ 0.229891] pnp: PnP ACPI: disabled226machine # [ 0.234160] NET: Registered PF_INET protocol family227machine # [ 0.234821] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)228machine # [ 0.266144] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)229machine # [ 0.266189] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)230machine # [ 0.266224] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)231machine # [ 0.266399] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)232machine # [ 0.266679] TCP: Hash tables configured (established 32768 bind 32768)233machine # [ 0.266771] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear)234machine # [ 0.266815] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)235machine # [ 0.266875] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)236machine # [ 0.266988] NET: Registered PF_UNIX/PF_LOCAL protocol family237machine # [ 0.267071] NET: Registered PF_XDP protocol family238machine # [ 0.267089] PCI: CLS 0 bytes, default 64239machine # [ 0.267354] Trying to unpack rootfs image as initramfs...240machine # [ 0.276586] kvm [1]: HYP mode not available241machine # [ 0.340788] Initialise system trusted keyrings242machine # [ 0.340857] Key type blacklist registered243machine # [ 0.341009] workingset: timestamp_bits=42 max_order=20 bucket_order=0244machine # [ 0.341632] squashfs: version 4.0 (2009/01/31) Phillip Lougher245machine # [ 0.341716] 9p: Installing v9fs 9p2000 file system support246machine # [ 0.341823] integrity: Platform Keyring initialized247machine # [ 0.341833] integrity: Machine keyring initialized248machine # [ 0.360434] Key type asymmetric registered249machine # [ 0.360440] Asymmetric key parser 'x509' registered250machine # [ 0.360488] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)251machine # [ 0.364477] io scheduler mq-deadline registered252machine # [ 0.364487] io scheduler kyber registered253machine # [ 0.376593] pl061_gpio 9030000.pl061: PL061 GPIO chip registered254machine # [ 0.380479] ledtrig-cpu: registered to indicate activity on CPUs255machine # [ 0.380988] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:256machine # [ 0.381005] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000257machine # [ 0.381015] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000258machine # [ 0.381020] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000259machine # [ 0.381048] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits260machine # [ 0.381071] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]261machine # [ 0.381158] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00262machine # [ 0.381165] pci_bus 0000:00: root bus resource [bus 00-ff]263machine # [ 0.381180] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]264machine # [ 0.381184] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]265machine # [ 0.381187] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]266machine # [ 0.381301] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint267machine # [ 0.381837] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint268machine # [ 0.382057] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]269machine # [ 0.382069] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]270machine # [ 0.382106] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]271machine # [ 0.382118] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]272machine # [ 0.382607] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint273machine # [ 0.382804] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]274machine # [ 0.382820] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]275machine # [ 0.382847] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]276machine # [ 0.383339] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint277machine # [ 0.383627] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]278machine # [ 0.383639] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]279machine # [ 0.383665] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]280machine # [ 0.384163] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint281machine # [ 0.384379] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]282machine # [ 0.384394] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]283machine # [ 0.384448] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]284machine # [ 0.384460] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]285machine # [ 0.384958] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint286machine # [ 0.385163] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]287machine # [ 0.385189] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]288machine # [ 0.385712] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint289machine # [ 0.385948] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]290machine # [ 0.385974] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]291machine # [ 0.386397] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint292machine # [ 0.386616] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]293machine # [ 0.386893] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint294machine # [ 0.387103] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]295machine # [ 0.387130] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]296machine # [ 0.387654] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint297machine # [ 0.387850] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]298machine # [ 0.387879] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]299machine # [ 0.388366] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint300machine # [ 0.396660] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]301machine # [ 0.396693] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]302machine # [ 0.397252] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint303machine # [ 0.397705] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]304machine # [ 0.397725] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]305machine # [ 0.397753] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]306machine # [ 0.398356] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint307machine # [ 0.398599] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]308machine # [ 0.398611] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]309machine # [ 0.398643] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]310machine # [ 0.399333] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned311machine # [ 0.399343] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned312machine # [ 0.399347] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned313machine # [ 0.399394] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned314machine # [ 0.399438] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned315machine # [ 0.399555] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned316machine # [ 0.399622] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned317machine # [ 0.399683] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned318machine # [ 0.399733] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned319machine # [ 0.399789] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned320machine # [ 0.399844] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned321machine # [ 0.399894] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned322machine # [ 0.399988] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned323machine # [ 0.400042] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned324machine # [ 0.400060] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned325machine # [ 0.400079] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned326machine # [ 0.400097] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned327machine # [ 0.400115] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned328machine # [ 0.400138] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned329machine # [ 0.400156] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned330machine # [ 0.400176] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned331machine # [ 0.400194] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned332machine # [ 0.400212] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned333machine # [ 0.400231] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned334machine # [ 0.400249] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned335machine # [ 0.400267] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned336machine # [ 0.400285] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned337machine # [ 0.400303] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned338machine # [ 0.400321] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned339machine # [ 0.400339] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned340machine # [ 0.400357] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned341machine # [ 0.400383] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]342machine # [ 0.400388] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]343machine # [ 0.400391] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]344machine # [ 0.401409] pci 0000:00:07.0: enabling device (0000 -> 0002)345machine # [ 0.431034] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)346machine # [ 0.433557] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)347machine # [ 0.435562] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)348machine # [ 0.445611] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)349machine # [ 0.447709] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)350machine # [ 0.449732] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)351machine # [ 0.451715] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)352machine # [ 0.461709] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)353machine # [ 0.463650] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)354machine # [ 0.465592] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)355machine # [ 0.467964] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)356machine # [ 0.489836] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled357machine # [ 0.491666] msm_serial: driver initialized358machine # [ 0.491808] SuperH (H)SCI(F) driver initialized359machine # [ 0.491866] STM32 USART driver initialized360machine # [ 0.511657] loop: module loaded361machine # [ 0.511882] virtio_blk virtio2: 2/0/0 default/read/poll queues362machine # [ 0.513265] virtio_blk virtio2: [vda] 16777216 512-byte logical blocks (8.59 GB/8.00 GiB)363machine # [ 0.517619] megasas: 07.734.00.00-rc1364machine # [ 0.518430] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]365machine # [ 0.520405] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000366machine # [ 0.523210] Intel/Sharp Extended Query Table at 0x0031367machine # [ 0.525687] Using buffer write method368machine # [ 0.525784] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]369machine # [ 0.527685] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000370machine # [ 0.527704] Intel/Sharp Extended Query Table at 0x0031371machine # [ 0.533574] Using buffer write method372machine # [ 0.533592] Concatenating MTD devices:373machine # [ 0.533594] (0): "0.flash"374machine # [ 0.533596] (1): "0.flash"375machine # [ 0.533598] into device "0.flash"376machine # [ 0.716693] Freeing initrd memory: 25244K377machine # [ 0.726698] tun: Universal TUN/TAP device driver, 1.6378machine # [ 0.732357] thunder_xcv, ver 1.0379machine # [ 0.732399] thunder_bgx, ver 1.0380machine # [ 0.732583] nicpf, ver 1.0381machine # [ 0.733470] e1000: Intel(R) PRO/1000 Network Driver382machine # [ 0.733478] e1000: Copyright (c) 1999-2006 Intel Corporation.383machine # [ 0.733518] e1000e: Intel(R) PRO/1000 Network Driver384machine # [ 0.733529] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.385machine # [ 0.733565] igb: Intel(R) Gigabit Ethernet Network Driver386machine # [ 0.733570] igb: Copyright (c) 2007-2014 Intel Corporation.387machine # [ 0.733599] igbvf: Intel(R) Gigabit Virtual Function Network Driver388machine # [ 0.733605] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.389machine # [ 0.733824] sky2: driver version 1.30390machine # [ 0.736513] usbcore: registered new interface driver usb-storage391machine # [ 0.736583] usbcore: registered new interface driver usbserial_generic392machine # [ 0.736602] usbserial: USB Serial support registered for generic393machine # [ 0.737565] hv_vmbus: registering driver hyperv_keyboard394machine # [ 0.738979] rtc-pl031 9010000.pl031: registered as rtc0395machine # [ 0.739019] rtc-pl031 9010000.pl031: setting system clock to 2026-11-12T16:57:15 UTC (1794502635)396machine # [ 0.739546] i2c_dev: i2c /dev entries driver397machine # [ 0.741234] ehci-pci 0000:00:07.0: EHCI Host Controller398machine # [ 0.741263] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1399machine # [ 0.741549] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000400machine # [ 0.744652] sdhci: Secure Digital Host Controller Interface driver401machine # [ 0.744662] sdhci: Copyright(c) Pierre Ossman402machine # [ 0.745129] Synopsys Designware Multimedia Card Interface Driver403machine # [ 0.745774] sdhci-pltfm: SDHCI platform and OF driver helper404machine # [ 0.748316] hid: raw HID events driver (C) Jiri Kosina405machine # [ 0.748798] usbcore: registered new interface driver usbhid406machine # [ 0.748804] usbhid: USB HID core driver407machine # [ 0.752921] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00408machine # [ 0.753489] hub 1-0:1.0: USB hub found409machine # [ 0.753514] hub 1-0:1.0: 6 ports detected410machine # [ 0.755380] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available411machine # [ 0.758128] drop_monitor: Initializing network drop monitor service412machine # [ 0.758389] NET: Registered PF_INET6 protocol family413machine # [ 0.759298] Segment Routing with IPv6414machine # [ 0.759350] In-situ OAM (IOAM) with IPv6415machine # [ 0.759448] NET: Registered PF_PACKET protocol family416machine # [ 0.759601] 9pnet: Installing 9P2000 support417machine # [ 0.759658] Key type dns_resolver registered418machine # [ 0.770045] registered taskstats version 1419machine # [ 0.770328] Loading compiled-in X.509 certificates420machine # [ 0.786171] Demotion targets for Node 0: null421machine # [ 0.786351] Key type .fscrypt registered422machine # [ 0.786357] Key type fscrypt-provisioning registered423machine # [ 0.786488] ima: No TPM chip found, activating TPM-bypass!424machine # [ 0.786512] ima: Allocated hash algorithm: sha1425machine # [ 0.786589] ima: No architecture policies found426machine # [ 0.787580] input: gpio-keys as /devices/platform/gpio-keys/input/input0427machine # [ 0.809846] clk: Disabling unused clocks428machine # [ 0.809862] PM: genpd: Disabling unused power domains429machine # [ 0.817143] Freeing unused kernel memory: 7808K430machine # [ 0.817381] Run /init as init process431machine # [ 0.844211] systemd[1]: Successfully made /usr/ read-only.432machine # [ 1.008496] usb 1-1: new high-speed USB device number 2 using ehci-pci433machine # [ 1.160366] 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.178356] 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.178384] systemd[1]: Detected virtualization qemu.436machine # [ 1.178425] systemd[1]: Detected architecture arm64.437machine # [ 1.178434] systemd[1]: Running in initrd.438machine # [ 1.178927] systemd[1]: Initializing machine ID from random generator.439machine # [ 1.179169] systemd[1]: Hostname set to <machine>.440machine # [ 1.276464] 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.325667] systemd[1]: bpf-restrict-fs: LSM BPF program attached442machine # [ 1.387930] systemd[1]: Queued start job for default target Initrd Default Target.443machine # [ 1.396483] usb 1-2: new high-speed USB device number 3 using ehci-pci444machine # [ 1.407725] systemd[1]: Created slice Slice /system/modprobe.445machine # [ 1.407985] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.446machine # [ 1.408030] systemd[1]: Expecting device /dev/disk/by-label/nixos...447machine # [ 1.408067] systemd[1]: Reached target Path Units.448machine # [ 1.408092] systemd[1]: Reached target Slice Units.449machine # [ 1.408117] systemd[1]: Reached target Swaps.450machine # [ 1.408143] systemd[1]: Reached target Timer Units.451machine # [ 1.408392] systemd[1]: Listening on D-Bus System Message Bus Socket.452machine # [ 1.408699] systemd[1]: Listening on Journal Socket (/dev/log).453machine # [ 1.408880] systemd[1]: Listening on Journal Sockets.454machine # [ 1.408994] systemd[1]: Listening on udev Kernel Socket.455machine # [ 1.409234] systemd[1]: Listening on udev Varlink Socket.456machine # [ 1.409264] systemd[1]: Reached target Socket Units.457machine # [ 1.411190] systemd[1]: Starting Create List of Static Device Nodes...458machine # [ 1.411275] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs459machine # [ 1.418075] systemd[1]: Mounting Kernel Configuration File System...460machine # [ 1.431178] systemd[1]: Starting Journal Service...461machine # [ 1.433650] systemd[1]: Starting Load Kernel Modules...462machine # [ 1.433783] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os463machine # [ 1.438148] systemd[1]: Starting Coldplug All udev Devices...464machine # [ 1.440103] systemd[1]: Finished Create List of Static Device Nodes.465machine # [ 1.449918] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...466machine # [ 1.468654] virtio_dma_buf: module verification failed: signature and/or required key missing - tainting kernel467machine # [ 1.477277] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0468machine # [ 1.477305] systemd[1]: Mounted Kernel Configuration File System.469machine # [ 1.477576] [drm] features: -virgl +edid -resource_blob -host_visible470machine # [ 1.477581] [drm] features: -context_init471machine # [ 1.478452] [drm] number of scanouts: 1472machine # [ 1.478466] [drm] number of cap sets: 0473machine # [ 1.485809] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic474machine # [ 1.485824] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0475machine # [ 1.506728] Console: switching to colour frame buffer device 160x50476machine # [ 1.516202] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device477machine # [ 1.517269] systemd-journald[78]: Collecting audit messages is disabled.478machine # [ 1.520141] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.479machine # [ 1.520601] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.480machine # [ 1.524517] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev481machine # [ 1.536642] systemd[1]: Starting Create Static Device Nodes in /dev...482machine # [ 1.537411] systemd[1]: Finished Load Kernel Modules.483machine # [ 1.544757] systemd[1]: Starting Apply Kernel Variables...484machine # [ 1.562981] 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/input2485machine # [ 1.566502] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0486machine # [ 1.577409] systemd[1]: Finished Create Static Device Nodes in /dev.487machine # [ 1.577802] systemd[1]: Reached target Preparation for Local File Systems.488machine # [ 1.578416] systemd[1]: Reached target Local File Systems.489machine # [ 1.589455] systemd[1]: Starting Rule-based Manager for Device Events and Files...490machine # [ 1.593797] systemd[1]: Finished Apply Kernel Variables.491machine # [ 1.596067] systemd[1]: Started Journal Service.492machine # [ 1.589501] systemd-modules-load[79]: Using 2 probe threads493machine # [ 1.593472] systemd-modules-load[79]: Module 'virtio_balloon' is built in494machine # [ 1.596434] systemd-modules-load[79]: Module 'virtio_console' is built in495machine # [ 1.600595] systemd-modules-load[79]: Inserted module 'dm_mod'496machine # [ 1.602064] systemd-modules-load[79]: Module 'virtio_rng' is built in497machine # [ 1.603251] systemd-modules-load[79]: Inserted module 'virtio_gpu'498machine # [ 1.612594] systemd[1]: Starting Create System Files and Directories...499machine # [ 1.632838] systemd[1]: Finished Create System Files and Directories.500machine # [ 1.639031] systemd-udevd[88]: Using default interface naming scheme 'v261'.501machine # [ 1.655161] systemd[1]: Started Rule-based Manager for Device Events and Files.502machine # [ 1.696364] systemd[1]: Starting Virtual Console Setup...503machine # [ 1.724539] systemd-vconsole-setup[110]: Configuration of first virtual console was skipped, ignoring remaining ones.504machine # [ 1.728123] systemd[1]: Finished Virtual Console Setup.505machine # [ 2.151559] systemd[1]: Finished Coldplug All udev Devices.506machine # [ 2.152704] systemd[1]: Reached target System Initialization.507machine # [ 2.153562] systemd[1]: Reached target Basic System.508machine # [ 2.271518] (udev-worker)[108]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.509machine # [ 2.275437] (udev-worker)[108]: Network interface NamePolicy= disabled on kernel command line.510machine # [ 2.278261] (udev-worker)[104]: Network interface NamePolicy= disabled on kernel command line.511machine # [ 2.295800] systemd[1]: Found device /dev/disk/by-label/nixos.512machine # [ 2.298690] systemd[1]: Reached target Initrd Root Device.513machine # [ 2.300622] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...514machine # [ 2.334004] systemd-fsck[128]: nixos: clean, 12/524288 files, 58513/2097152 blocks515machine # [ 2.338597] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.516machine # [ 2.433216] systemd[1]: Mounting /sysroot...517machine # [ 2.466876] EXT4-fs (vda): mounted filesystem 1b4100e5-9af7-4880-b241-233448e499af r/w with ordered data mode. Quota mode: none.518machine # [ 2.463821] systemd[1]: Mounted /sysroot.519machine # [ 2.467494] systemd[1]: Reached target Initrd Root File System.520machine # [ 2.474478] systemd[1]: Mounting /sysroot/nix/.ro-store...521machine # [ 2.480331] systemd[1]: Mounting /sysroot/nix/.rw-store...522machine # [ 2.488317] systemd[1]: Mounting /sysroot/run...523machine # [ 2.493041] systemd[1]: Mounting /sysroot/tmp/shared...524machine # [ 2.508270] systemd[1]: Mounting /sysroot/tmp/xchg...525machine # [ 2.525091] systemd[1]: Starting Mountpoints Configured in the Real Root...526machine # [ 2.526649] systemd[1]: Mounted /sysroot/nix/.rw-store.527machine # [ 2.533779] systemd[1]: Starting rw-sysroot-nix-store.service...528machine # [ 2.567311] fuse: init (API version 7.45)529machine # [ 2.562942] systemd-sysroot-fstab-check[141]: /sysroot should be mounted in the initrd, will request daemon-reload.530machine # [ 2.572475] systemd[1]: Mounted /sysroot/run.531machine # [ 2.613303] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.532machine # [ 2.625715] systemd[1]: Finished rw-sysroot-nix-store.service.533machine # [ 2.626728] systemd[1]: Reload requested from client PID 141 ('systemd-sysroot') (unit initrd-parse-etc.service)...534machine # [ 2.629693] systemd[1]: Reloading...535machine # [ 2.656226] virtiofs virtio6: discovered new tag: nix-store536machine # [ 2.684954] virtiofs virtio6: virtio_fs_setup_dax: No cache capability537machine # [ 2.702646] virtiofs virtio7: discovered new tag: shared538machine # [ 2.703519] virtiofs virtio7: virtio_fs_setup_dax: No cache capability539machine # [ 2.708519] virtiofs virtio8: discovered new tag: xchg540machine # [ 2.709364] virtiofs virtio8: virtio_fs_setup_dax: No cache capability541machine # [ 2.795918] systemd[1]: Reloading finished in 170 ms.542machine # [ 2.832996] systemd-sysroot-fstab-check[141]: Requesting initrd-fs.target/start/replace...543machine # [ 2.835622] systemd[1]: Mounted /sysroot/nix/.ro-store.544machine # [ 2.837755] systemd[1]: Mounted /sysroot/tmp/shared.545machine # [ 2.839082] systemd[1]: Mounted /sysroot/tmp/xchg.546machine # [ 2.841169] systemd-sysroot-fstab-check[141]: Requesting swap.target/start/replace...547machine # [ 2.846398] systemd[1]: Starting rw-sysroot-nix-store.service...548machine # [ 2.848216] systemd[1]: initrd-parse-etc.service: Deactivated successfully.549machine # [ 2.850311] systemd[1]: Finished Mountpoints Configured in the Real Root.550machine # [ 2.852795] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.551machine # [ 2.869027] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.552machine # [ 2.871516] systemd[1]: Finished rw-sysroot-nix-store.service.553machine # [ 3.179270] (udev-worker)[98]: mtd0ro: Failed to find and pin callout binary "/nix/store/rzzrvlm7r31iq3im3h66nhxc2zh996l9-systemd-262/lib/udev/mtd_probe": No such file or directory554machine # [ 3.184089] (udev-worker)[98]: mtd0ro: /etc/udev/rules.d/75-probe_mtd.rules:5 IMPORT{program}="mtd_probe $devnode": Failed to execute "mtd_probe /dev/mtd0ro", ignoring: No such file or directory555machine # [ 3.198308] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.556machine # [ 3.200170] systemd[1]: Stopped Virtual Console Setup.557machine # [ 3.203165] systemd[1]: Stopping Virtual Console Setup...558machine # [ 3.205245] systemd[1]: Starting Virtual Console Setup...559machine # [ 3.210803] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.560machine # [ 3.216089] systemd[1]: Stopped Virtual Console Setup.561machine # [ 3.217782] systemd[1]: Starting Virtual Console Setup...562machine # [ 3.254929] systemd-vconsole-setup[180]: Configuration of first virtual console was skipped, ignoring remaining ones.563machine # [ 3.257059] systemd[1]: Finished Virtual Console Setup.564machine # [ 3.434963] systemd[1]: Mounting /sysroot/nix/store...565machine # [ 3.481172] systemd[1]: Mounted /sysroot/nix/store.566machine # [ 3.482409] systemd[1]: Reached target Initrd File Systems.567machine # [ 3.484467] systemd[1]: Starting Find NixOS closure...568machine # [ 3.488090] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...569machine # [ 3.520268] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.570machine # [ 3.522186] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.571machine # [ 3.527794] systemd[1]: Finished Find NixOS closure.572machine # [ 3.529463] systemd[1]: Reached target Initrd Default Target.573machine # [ 3.530808] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...574machine # [ 3.552177] systemd[1]: Stopped target Initrd Default Target.575machine # [ 3.553532] systemd[1]: Stopped target Basic System.576machine # [ 3.554658] systemd[1]: Stopped target Initrd Root Device.577machine # [ 3.555928] systemd[1]: Stopped target Path Units.578machine # [ 3.557111] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.579machine # [ 3.558717] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.580machine # [ 3.560453] systemd[1]: Stopped target Slice Units.581machine # [ 3.561534] systemd[1]: Stopped target Socket Units.582machine # [ 3.562637] systemd[1]: Stopped target System Initialization.583machine # [ 3.563896] systemd[1]: Stopped target Swaps.584machine # [ 3.566943] systemd[1]: Stopped target Timer Units.585machine # [ 3.569616] systemd[1]: dbus.socket: Deactivated successfully.586machine # [ 3.571858] systemd[1]: Closed D-Bus System Message Bus Socket.587machine # [ 3.573870] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.588machine # [ 3.577226] systemd[1]: Stopped Find NixOS closure.589machine # [ 3.579454] systemd[1]: Starting rw-sysroot-nix-store.service...590machine # [ 3.582343] systemd[1]: systemd-sysctl.service: Deactivated successfully.591machine # [ 3.585180] systemd[1]: Stopped Apply Kernel Variables.592machine # [ 3.586381] systemd[1]: systemd-modules-load.service: Deactivated successfully.593machine # [ 3.590979] systemd[1]: Stopped Load Kernel Modules.594machine # [ 3.591968] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.595machine # [ 3.593999] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.596machine # [ 3.595310] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.597machine # [ 3.596954] systemd[1]: Stopped Create System Files and Directories.598machine # [ 3.597985] systemd[1]: Stopped target Local File Systems.599machine # [ 3.598901] systemd[1]: Stopped target Preparation for Local File Systems.600machine # [ 3.599985] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.601machine # [ 3.601200] systemd[1]: Stopped Coldplug All udev Devices.602machine # [ 3.602081] systemd[1]: Stopping Rule-based Manager for Device Events and Files...603machine # [ 3.603481] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.604machine # [ 3.605090] systemd[1]: Stopped Virtual Console Setup.605machine # [ 3.606004] systemd[1]: initrd-cleanup.service: Deactivated successfully.606machine # [ 3.607138] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.607machine # [ 3.608184] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.608machine # [ 3.609272] systemd[1]: Finished rw-sysroot-nix-store.service.609machine # [ 3.610161] systemd[1]: systemd-udevd.service: Deactivated successfully.610machine # [ 3.611169] systemd[1]: Stopped Rule-based Manager for Device Events and Files.611machine # [ 3.612358] systemd[1]: systemd-udevd.service: Consumed 1.742s CPU time over 2.024s wall clock time, 30.8M memory peak.612machine # [ 3.613900] systemd[1]: systemd-udevd-varlink.socket: Deactivated successfully.613machine # [ 3.615001] systemd[1]: Closed udev Varlink Socket.614machine # [ 3.615794] systemd[1]: Starting Cleanup udev Database...615machine # [ 3.616742] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.616machine # [ 3.617891] systemd[1]: Stopped Create Static Device Nodes in /dev.617machine # [ 3.618834] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.618machine # [ 3.620262] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.619machine # [ 3.621341] systemd[1]: kmod-static-nodes.service: Deactivated successfully.620machine # [ 3.622378] systemd[1]: Stopped Create List of Static Device Nodes.621machine # [ 3.676693] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.622machine # [ 3.678085] systemd[1]: Finished Cleanup udev Database.623machine # [ 3.678954] systemd[1]: Reached target Switch Root.624machine # [ 3.685020] systemd[1]: Starting NixOS Activation...625machine # [ 3.776640] initrd-nixos-activation-start[203]: booting system configuration /nix/store/sxvg1zjz3k40v3aricf5f7yvydyjl6qf-nixos-system-machine-test626machine # [ 3.808377] initrd-nixos-activation-start[203]: running activation script...627machine # [ 4.079553] initrd-nixos-activation-start[226]: setting up /etc...628machine # [ 4.228379] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.629machine # [ 4.229715] systemd[1]: Finished NixOS Activation.630machine # [ 4.231302] systemd[1]: Starting Switch Root...631machine # [ 4.279919] systemd[1]: Switching root.632machine # [ 4.402678] systemd-journald[78]: Received SIGTERM from PID 1 (systemd).633machine # [ 4.941761] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)634machine # [ 4.943061] systemd[1]: Detected virtualization qemu.635machine # [ 4.943601] systemd[1]: Detected architecture arm64.636machine # [ 4.944123] systemd[1]: Detected first boot.637machine # [ 4.956628] systemd[1]: Initializing machine ID from random generator.638machine # [ 5.089081] systemd[1]: bpf-restrict-fs: LSM BPF program attached639machine # [ 5.205820] systemd[1]: Applying preset policy.640machine # [ 5.423504] systemd[1]: Populated /etc with preset unit settings.641machine # [ 5.658094] systemd[1]: initrd-switch-root.service: Deactivated successfully.642machine # [ 5.659007] systemd[1]: Stopped initrd-switch-root.service.643machine # [ 5.661287] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.644machine # [ 5.664656] systemd[1]: Created slice Slice /system/getty.645machine # [ 5.666278] systemd[1]: Created slice User and Session Slice.646machine # [ 5.666921] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.647machine # [ 5.667585] systemd[1]: Started Forward Password Requests to Wall Directory Watch.648machine # [ 5.668169] systemd[1]: Expecting device /dev/hvc0...649machine # [ 5.670467] systemd[1]: Expecting device /dev/ttyAMA0...650machine # [ 5.670940] systemd[1]: Reached target Local Encrypted Volumes.651machine # [ 5.671697] systemd[1]: Stopped target initrd-fs.target.652machine # [ 5.672316] systemd[1]: Stopped target initrd-root-fs.target.653machine # [ 5.672944] systemd[1]: Stopped target initrd-switch-root.target.654machine # [ 5.673583] systemd[1]: Reached target Virtual Machines and Containers.655machine # [ 5.674199] systemd[1]: Reached target Path Units.656machine # [ 5.674782] systemd[1]: Reached target Remote File Systems.657machine # [ 5.675371] systemd[1]: Reached target Slice Units.658machine # [ 5.675988] systemd[1]: Reached target Swaps.659machine # [ 5.677882] systemd[1]: Listening on Query the User Interactively for a Password.660machine # [ 5.679978] systemd[1]: Listening on Process Core Dump Socket.661machine # [ 5.681541] systemd[1]: Listening on Credential Encryption/Decryption.662machine # [ 5.682960] systemd[1]: Listening on Factory Reset Management.663machine # [ 5.683578] systemd[1]: Listening on Hostname Service Socket.664machine # [ 5.688720] systemd[1]: Starting Journal Log Access Socket...665machine # [ 5.689919] systemd[1]: Listening on Journal Audit Socket.666machine # [ 5.691746] systemd[1]: Listening on Console Output Muting Service Socket.667machine # [ 5.692611] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.668machine # [ 5.693152] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os669machine # [ 5.693786] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki670machine # [ 5.697410] systemd[1]: Listening on Disk Repartitioning Service Socket.671machine # [ 5.698086] systemd[1]: Listening on udev Varlink Socket.672machine # [ 5.718973] systemd[1]: Mounting Huge Pages File System...673machine # [ 5.723753] systemd[1]: Mounting POSIX Message Queue File System...674machine # [ 5.731499] systemd[1]: Mounting Kernel Debug File System...675machine # [ 5.743449] systemd[1]: Mounting Kernel Trace File System...676machine # [ 5.748777] systemd[1]: Starting Create List of Static Device Nodes...677machine # [ 5.749435] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs678machine # [ 5.756603] systemd[1]: Mounting Kernel Configuration File System...679machine # [ 5.757026] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm680machine # [ 5.757323] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore681machine # [ 5.757603] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse682machine # [ 5.769008] systemd[1]: Mounting FUSE Control File System...683machine # [ 5.769432] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67684machine # [ 5.777418] systemd[1]: Starting Journal Service...685machine # [ 5.782493] systemd[1]: Starting Load Kernel Modules...686machine # [ 5.797593] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...687machine # [ 5.819830] systemd[1]: Starting Remount Root and Kernel File Systems...688machine # [ 5.820209] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os689machine # [ 5.825370] systemd[1]: Starting Coldplug All udev Devices...690machine # [ 5.827056] systemd[1]: Listening on Journal Log Access Socket.691machine # [ 5.842580] systemd[1]: Mounted Kernel Configuration File System.692machine # [ 5.843459] systemd[1]: Mounted Kernel Debug File System.693machine # [ 5.851246] systemd[1]: Mounted Huge Pages File System.694machine # [ 5.851807] systemd[1]: Mounted Kernel Trace File System.695machine # [ 5.852599] systemd[1]: Mounted POSIX Message Queue File System.696machine # [ 5.867767] systemd[1]: Mounted FUSE Control File System.697machine # [ 5.890357] systemd[1]: Finished Create List of Static Device Nodes.698machine # [ 5.893701] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...699machine # [ 5.917295] systemd-journald[298]: Collecting audit messages is enabled.700machine # [ 5.925663] systemd[1]: Finished Load Kernel Modules.701machine # [ 5.927691] EXT4-fs (vda): re-mounted 1b4100e5-9af7-4880-b241-233448e499af.702machine # [ 5.928680] systemd[1]: Starting Apply Kernel Variables...703machine # [ 5.934410] systemd[1]: Finished Remount Root and Kernel File Systems.704machine # [ 5.934977] systemd[1]: Listening on Disk Image Download Service Socket.705machine # [ 5.935268] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore706machine # [ 5.935114] systemd[1]: Queued start job for default target Multi-User System.707machine # [ 5.949017] systemd[1]: Starting Load/Save OS Random Seed...708machine # [ 5.949446] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os709machine # [ 5.950956] systemd[1]: Started Journal Service.710machine # [ 5.947734] systemd[1]: systemd-journald.service: Deactivated successfully.711machine # [ 5.953766] systemd-modules-load[299]: Using 2 probe threads712machine # [ 5.965654] systemd-modules-load[299]: Module 'atkbd' is built in713machine # [ 5.970593] systemd-modules-load[299]: Module 'loop' is built in714machine # [ 5.975108] systemd[1]: Starting Flush Journal to Persistent Storage...715machine # [ 6.010295] systemd-oomd[300]: No swap; memory pressure usage will be degraded716machine # [ 6.019714] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.717machine # [ 6.027474] systemd[1]: Starting Create Static Device Nodes in /dev...718machine # [ 6.032894] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.719machine # [ 6.044295] systemd-journald[298]: Received client request to flush runtime journal.720machine # [ 6.066514] systemd[1]: Finished Apply Kernel Variables.721machine # [ 6.068166] systemd[1]: Finished Load/Save OS Random Seed.722machine # [ 6.069604] systemd[1]: Reached target First Boot Complete.723machine # [ 6.070494] systemd[1]: Finished Flush Journal to Persistent Storage.724machine # [ 6.088967] systemd[1]: Finished Create Static Device Nodes in /dev.725machine # [ 6.089964] systemd[1]: Reached target Preparation for Local File Systems.726machine # [ 6.091795] systemd[1]: Starting Rule-based Manager for Device Events and Files...727machine # [ 6.139491] systemd-udevd[328]: Using default interface naming scheme 'v261'.728machine # [ 6.175363] systemd[1]: Started Rule-based Manager for Device Events and Files.729machine # [ 6.572298] systemd[1]: Finished Coldplug All udev Devices.730machine # [ 6.615866] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs731machine # [ 6.630695] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse732machine # [ 6.652391] systemd[1]: Mounting /run/wrappers...733machine # [ 6.687697] systemd[1]: Mounted /run/wrappers.734machine # [ 6.691469] systemd[1]: Reached target Local File Systems.735machine # [ 6.695594] systemd[1]: Listening on Boot Loader Control Service Socket.736machine # [ 6.696665] systemd[1]: Starting register-nix-paths.service...737machine # [ 6.699994] systemd[1]: Starting Create SUID/SGID Wrappers...738machine # [ 6.700951] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.739machine # [ 6.703457] systemd[1]: Starting Save Transient machine-id to Disk...740machine # [ 6.718848] systemd[1]: Starting Create System Files and Directories...741machine # [ 6.723417] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.742machine # [ 6.804992] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.743machine # [ 6.832134] systemd[1]: Finished Create System Files and Directories.744machine # [ 6.836089] systemd[1]: Starting Rebuild Journal Catalog...745machine # [ 6.838281] systemd[1]: Starting Record System Boot/Shutdown in UTMP...746machine # [ 6.873886] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.747machine # [ 6.877520] systemd[1]: Finished Save Transient machine-id to Disk.748machine # [ 6.904726] systemd[1]: Finished Record System Boot/Shutdown in UTMP.749machine # [ 6.927273] systemd[1]: Finished Rebuild Journal Catalog.750machine # [ 6.929852] systemd[1]: Starting Update is Completed...751machine # [ 6.965392] systemd[1]: Finished Update is Completed.752machine # [ 6.986217] (udev-worker)[350]: Network interface NamePolicy= disabled on kernel command line.753machine # [ 6.992829] (udev-worker)[340]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.754machine # [ 6.996766] (udev-worker)[340]: Network interface NamePolicy= disabled on kernel command line.755machine # [ 7.118173] systemd[1]: Condition check resulted in Virtio network device being skipped.756machine # [ 7.120867] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore757machine # [ 7.126175] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.758machine # [ 7.130459] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67759machine # [ 7.137724] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore760machine # [ 7.144243] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os761machine # [ 7.145631] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os762machine # [ 7.230618] mousedev: PS/2 mouse device common for all mice763machine # [ 7.228809] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.764machine # [ 7.232372] systemd[1]: Finished Create SUID/SGID Wrappers.765machine # [ 7.254012] systemd[1]: Finished register-nix-paths.service.766machine # [ 7.258989] systemd[1]: Reached target System Initialization.767machine # [ 7.265168] systemd[1]: Started Discard unused filesystem blocks once a week.768machine # [ 7.272245] systemd[1]: Started Daily Cleanup of Temporary Directories.769machine # [ 7.279692] systemd[1]: Reached target Timer Units.770machine # [ 7.285034] systemd[1]: Listening on D-Bus System Message Bus Socket.771machine # [ 7.292863] systemd[1]: Listening on Nix Daemon Socket.772machine # [ 7.297325] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.773machine # [ 7.305045] systemd[1]: Reached target Socket Units.774machine # [ 7.306209] systemd[1]: Reached target Basic System.775machine # [ 7.307559] systemd[1]: Started backdoor.service.776machine # [ 7.309582] systemd[1]: Starting Import lastlog data into lastlog2 database...777machine # [ 7.310725] systemd[1]: Starting Name Service Cache Daemon (nsncd)...778machine # [ 7.313216] systemd[1]: Starting Post-Boot Actions...779machine # [ 7.316887] systemd[1]: Started Reset console on configuration changes.780machine # connecting to host...781machine # [ 7.322094] systemd[1]: Starting resolvconf update...782machine # [ 7.322990] systemd[1]: Starting D-Bus System Message Bus...783[8.09s] machine: Guest shell says: b'Spawning backdoor root shell...\n'784[8.10s] machine: connected to guest root shell785[8.10s] machine: (connecting took 7.68 seconds)786[8.10s] machine: (finished: waiting for the VM to finish booting, in 8.10 seconds)787machine # [ 7.388931] systemd[1]: Finished Post-Boot Actions.788machine # [ 7.405495] systemd[1]: Started Name Service Cache Daemon (nsncd).789machine # [ 7.413046] systemd[1]: Reached target Host and Network Name Lookups.790machine # [ 7.421154] nsncd[432]: Nov 12 16:57:22.175 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"791machine # [ 7.423283] systemd[1]: Reached target User and Group Name Lookups.792machine # [ 7.435265] systemd[1]: Starting User Login Management...793machine # [ 7.484948] systemd[1]: Finished Import lastlog data into lastlog2 database.794machine # [ 7.492192] dbus-broker-launch[438]: Looking up NSS user entry for 'systemd-timesync'...795machine # [ 7.499717] dbus-broker-launch[438]: NSS returned no entry for 'systemd-timesync'796machine # [ 7.502071] dbus-broker-launch[438]: Invalid user-name in /nix/store/zwpdq5dl6mgp5cnkswh4wmrmps0m71lm-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"797machine # [ 7.525971] systemd[1]: Started D-Bus System Message Bus.798machine # [ 7.542551] dbus-broker-launch[438]: Ready799machine # [ 7.559598] systemd-logind[461]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)800machine # [ 7.563417] systemd-logind[461]: Watching system buttons on /dev/input/event0 (gpio-keys)801machine # [ 7.565170] systemd-logind[461]: New seat seat0.802machine # [ 7.570199] systemd[1]: Started User Login Management.803machine # [ 7.572241] systemd[1]: Starting linger-users.service...804machine # [ 7.586374] systemd[1]: Stopped target Host and Network Name Lookups.805machine # [ 7.591157] systemd[1]: Stopping Host and Network Name Lookups...806machine # [ 7.593090] systemd[1]: Stopped target User and Group Name Lookups.807machine # [ 7.596073] systemd[1]: Stopping User and Group Name Lookups...808machine # [ 7.596988] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...809machine # [ 7.597879] systemd[1]: nscd.service: Deactivated successfully.810machine # [ 7.605179] systemd[1]: Stopped Name Service Cache Daemon (nsncd).811machine # [ 7.607545] systemd[1]: Starting Name Service Cache Daemon (nsncd)...812machine # [ 7.628086] systemd[1]: linger-users.service: Deactivated successfully.813machine # [ 7.641023] systemd[1]: Finished linger-users.service.814machine # [ 7.668535] systemd[1]: Finished resolvconf update.815machine # [ 7.673497] systemd[1]: Reached target Preparation for Network.816machine # [ 7.675606] nsncd[515]: Nov 12 16:57:22.442 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"817machine # [ 7.681373] systemd[1]: Starting DHCP Client...818machine # [ 7.685068] systemd[1]: Starting Address configuration of eth1...819machine # [ 7.691770] systemd[1]: Starting Extra networking commands....820machine # [ 7.692883] systemd[1]: Started Name Service Cache Daemon (nsncd).821machine # [ 7.693750] systemd[1]: Reached target Host and Network Name Lookups.822machine # [ 7.696366] systemd[1]: Reached target User and Group Name Lookups.823machine # [ 7.767092] network-addresses-eth1-start[541]: adding address 192.168.1.1/24... done824machine # [ 7.776423] network-addresses-eth1-start[541]: adding address 2001:db8:1::1/64... done825machine # [ 7.789377] systemd[1]: Finished Address configuration of eth1.826machine # [ 7.838911] dhcpcd[550]: dhcpcd-10.3.2 starting827machine # [ 7.842934] dhcpcd[583]: dev: loaded udev828machine # [ 7.870712] 8021q: 802.1Q VLAN Support v1.8829machine # [ 7.871104] 8021q: adding VLAN 0 to HW filter on device eth1830machine # [ 7.926609] cfg80211: Loading compiled-in X.509 certificates for regulatory database831machine # [ 7.927511] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'832machine # [ 7.927968] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'833machine # [ 7.932317] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2834machine # [ 7.934009] cfg80211: failed to load regulatory.db835machine # [ 7.954732] systemd[1]: Finished Extra networking commands..836machine # [ 7.955652] systemd[1]: Reached target Network.837machine # [ 7.965511] systemd[1]: Starting PostgreSQL Server...838machine # [ 7.966317] systemd[1]: Started RustFS S3-compatible object storage.839machine # [ 7.976607] systemd[1]: Starting Setup RustFS bucket...840machine # [ 7.984233] systemd[1]: Starting Permit User Sessions...841machine # [ 8.037159] dhcpcd[583]: eth0: waiting for carrier842machine # [ 8.038234] dhcpcd[583]: eth0: carrier acquired843machine # [ 8.044532] 8021q: adding VLAN 0 to HW filter on device eth0844machine # [ 8.053743] systemd[1]: Finished Permit User Sessions.845machine # [ 8.057930] systemd[1]: Started Getty on tty1.846machine # [ 8.060257] systemd[1]: Reached target Login Prompts.847machine # [ 8.071226] dhcpcd[583]: DUID 00:01:00:01:32:88:ac:72:52:54:00:12:34:56848machine # [ 8.072376] dhcpcd[583]: eth0: IAID 00:12:34:56849machine # [ 8.073118] dhcpcd[583]: eth0: adding address fe80::5054:ff:fe12:3456850machine # [ 8.289736] postgresql-pre-start[637]: The files belonging to this database system will be owned by user "postgres".851machine # [ 8.292158] postgresql-pre-start[637]: This user must also own the server process.852machine # [ 8.297212] postgresql-pre-start[637]: The database cluster will be initialized with locale "en_US.UTF-8".853machine # [ 8.298593] postgresql-pre-start[637]: The default database encoding has accordingly been set to "UTF8".854machine # [ 8.302483] postgresql-pre-start[637]: The default text search configuration will be set to "english".855machine # [ 8.307027] postgresql-pre-start[637]: Data page checksums are enabled.856machine # [ 8.308455] postgresql-pre-start[637]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok857machine # [ 8.312452] postgresql-pre-start[637]: creating subdirectories ... ok858machine # [ 8.314917] postgresql-pre-start[637]: selecting dynamic shared memory implementation ... posix859machine # [ 8.396813] postgresql-pre-start[637]: selecting default "max_connections" ... 100860machine # [ 8.551028] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input3861machine # [ 8.546468] postgresql-pre-start[637]: selecting default "shared_buffers" ... 128MB862machine # [ 8.799154] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.863machine # [ 8.807221] systemd[1]: Starting Virtual Console Setup...864machine # [ 8.831499] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.865machine # [ 8.832902] systemd[1]: Stopped Virtual Console Setup.866machine # [ 8.840523] systemd[1]: Starting Virtual Console Setup...867machine # [ 8.859860] systemd-logind[461]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)868machine # [ 8.969546] systemd-vconsole-setup[675]: Configuration of first virtual console was skipped, ignoring remaining ones.869machine # [ 8.975367] systemd[1]: Finished Virtual Console Setup.870machine # [ 9.270609] postgresql-pre-start[637]: selecting default time zone ... UTC871machine # [ 9.272570] postgresql-pre-start[637]: creating configuration files ... ok872machine # [ 9.521399] postgresql-pre-start[637]: running bootstrap script ... ok873machine # [ 9.766000] dhcpcd[583]: eth0: soliciting an IPv6 router874machine # [ 9.767529] dhcpcd[583]: eth0: Router Advertisement from fe80::2875machine # [ 9.769098] dhcpcd[583]: eth0: adding address fec0::5054:ff:fe12:3456/64876machine # [ 9.770606] dhcpcd[583]: eth0: adding route to fec0::/64877machine # [ 9.771989] dhcpcd[583]: eth0: adding default route via fe80::2878machine # [ 9.897701] dhcpcd[583]: eth0: soliciting a DHCP lease879machine # [ 9.904592] dhcpcd[583]: eth0: offered 10.0.2.15 from 10.0.2.2880machine # [ 9.912309] dhcpcd[583]: eth0: probing address 10.0.2.15/24881machine # [ 10.115036] postgresql-pre-start[637]: performing post-bootstrap initialization ... ok882machine # [ 10.254015] postgresql-pre-start[637]: syncing data to disk ... ok883machine # [ 10.255679] postgresql-pre-start[637]: initdb: warning: enabling "trust" authentication for local connections884machine # [ 10.258145] postgresql-pre-start[637]: 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.885machine # [ 10.261910] postgresql-pre-start[637]: Success. You can now start the database server using:886machine # [ 10.263825] postgresql-pre-start[637]: pg_ctl -D /var/lib/postgresql/18 -l logfile start887machine # [ 10.420444] postgres[694]: [694] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit888machine # [ 10.423721] postgres[694]: [694] LOG: listening on IPv4 address "0.0.0.0", port 5432889machine # [ 10.425992] postgres[694]: [694] LOG: listening on IPv6 address "::", port 5432890machine # [ 10.427696] postgres[694]: [694] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"891machine # [ 10.435867] postgres[703]: [703] LOG: database system was shut down at 2026-11-12 16:57:24 GMT892machine # [ 10.443896] postgres[694]: [694] LOG: database system is ready to accept connections893machine # [ 10.448727] systemd[1]: Started PostgreSQL Server.894machine # [ 10.456915] systemd[1]: Starting PostgreSQL Setup Scripts...895machine # [ 10.696190] postgresql-setup-start[714]: CREATE DATABASE896machine # [ 10.745505] postgresql-setup-start[719]: CREATE ROLE897machine # [ 10.767569] postgresql-setup-start[725]: ALTER DATABASE898machine # [ 10.776364] systemd[1]: Finished PostgreSQL Setup Scripts.899machine # [ 10.778439] systemd[1]: Reached target PostgreSQL.900machine # [ 15.059105] dhcpcd[583]: eth0: leased 10.0.2.15 for 86400 seconds901machine # [ 15.059358] dhcpcd[583]: eth0: adding route to 10.0.2.0/24902machine # [ 15.059434] dhcpcd[583]: eth0: adding default route via 10.0.2.2903machine # [ 15.177361] systemd[1]: Started DHCP Client.904machine # [ 15.178521] systemd[1]: Reached target Network is Online.905machine # [ 15.181683] systemd[1]: Starting k3s service...906machine # [ 15.254495] k3s[831]: time="2026-11-12T16:57:30Z" level=info msg="Acquiring lock file /var/lib/rancher/k3s/data/.lock"907machine # [ 15.258514] k3s[831]: time="2026-11-12T16:57:30Z" level=info msg="Preparing data dir /var/lib/rancher/k3s/data/b9f7776539d53e1567b480015e2ee0c0a8aa3ac6b7b20aaae82735601aa59b06"908machine # [ 15.821877] rustfs-setup-start[843]: mb s3://niks3909machine # [ 15.830610] systemd[1]: Finished Setup RustFS bucket.910machine # [ 18.638213] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Starting k3s 1.36.5+k3s1 (3dd98cc5)"911machine # [ 18.669743] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdle=20, maxOpen=0, maxLifetime=0s, maxIdleTime=2m0s"912machine # [ 18.673761] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Kine built with sqlite from github.com/mattn/go-sqlite3 version 3.53.3"913machine # [ 18.677460] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Configuring database table schema and indexes, this may take a moment..."914machine # [ 18.680302] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Database tables and indexes are up to date"915machine # [ 18.682321] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Running startup VACUUM to reclaim disk space, this may take a moment..."916machine # [ 18.684897] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Startup VACUUM completed successfully"917machine # [ 18.686844] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Kine available at unix://kine.sock"918machine # [ 18.688825] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"919machine # [ 18.691274] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="Datastore connection validated successfully, proceeding with bootstrap data generation"920machine # [ 18.694203] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="generated self-signed CA certificate CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:33.45607916 +0000 UTC notAfter=2036-11-09 15:57:33.45607916 +0000 UTC"921machine # [ 18.698369] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"922machine # [ 18.702648] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"923machine # [ 18.707144] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"924machine # [ 18.711411] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"925machine # [ 18.715417] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"926machine # [ 18.719398] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"927machine # [ 18.723249] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="generated self-signed CA certificate CN=k3s-server-ca@1794502653: notBefore=2026-11-12 15:57:33.46161096 +0000 UTC notAfter=2036-11-09 15:57:33.46161096 +0000 UTC"928machine # [ 18.726819] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-server-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"929machine # [ 18.730043] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=kube-scheduler signed by CN=k3s-server-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"930machine # [ 18.733268] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=kube-controller-manager signed by CN=k3s-server-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"931machine # [ 18.736459] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="generated self-signed CA certificate CN=k3s-request-header-ca@1794502653: notBefore=2026-11-12 15:57:33.46408 +0000 UTC notAfter=2036-11-09 15:57:33.46408 +0000 UTC"932machine # [ 18.739798] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"933machine # [ 18.742945] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="generated self-signed CA certificate CN=etcd-server-ca@1794502653: notBefore=2026-11-12 15:57:33.46513174 +0000 UTC notAfter=2036-11-09 15:57:33.46513174 +0000 UTC"934machine # [ 18.745925] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"935machine # [ 18.748561] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="generated self-signed CA certificate CN=etcd-peer-ca@1794502653: notBefore=2026-11-12 15:57:33.46618572 +0000 UTC notAfter=2036-11-09 15:57:33.46618572 +0000 UTC"936machine # [ 18.751279] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"937machine # [ 18.753838] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"938machine # [ 18.937800] k3s[831]: time="2026-11-12T16:57:33Z" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1794502653: notBefore=2026-11-12 15:57:33 +0000 UTC notAfter=2027-11-12 15:57:33 +0000 UTC"939machine # [ 18.940641] k3s[831]: time="2026-11-12T16:57:33Z" level=warning msg="dynamiclistener [::]:6443: no cached certificate available for preload - deferring certificate load until storage initialization or first client request"940machine # [ 18.945852] k3s[831]: time="2026-11-12T16:57:33Z" 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__530_692a_a8f_b554-478559:fec0::530:692a:a8f:b554 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=28C38227DE9755F8B959556DC552D71CA5E2D859]"941machine # [ 20.344716] k3s[831]: time="2026-11-12T16:57:35Z" level=info msg="Password verified locally for node machine"942machine # [ 20.347063] k3s[831]: time="2026-11-12T16:57:35Z" level=info msg="certificate CN=machine signed by CN=k3s-server-ca@1794502653: notBefore=2026-11-12 15:57:35 +0000 UTC notAfter=2027-11-12 15:57:35 +0000 UTC"943machine # [ 20.751577] k3s[831]: time="2026-11-12T16:57:35Z" level=info msg="certificate CN=system:node:machine,O=system:nodes signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:35 +0000 UTC notAfter=2027-11-12 15:57:35 +0000 UTC"944machine # [ 20.880800] k3s[831]: time="2026-11-12T16:57:35Z" level=info msg="certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:35 +0000 UTC notAfter=2027-11-12 15:57:35 +0000 UTC"945machine # [ 21.031310] k3s[831]: time="2026-11-12T16:57:35Z" level=info msg="certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1794502653: notBefore=2026-11-12 15:57:35 +0000 UTC notAfter=2027-11-12 15:57:35 +0000 UTC"946machine # [ 21.174821] k3s[831]: time="2026-11-12T16:57:35Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:51866: runtime core not ready"947machine # [ 21.298201] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Module overlay was already loaded"948machine # [ 21.357284] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.949machine # [ 21.359766] Bridge firewalling registered950machine # [ 21.362181] k3s[831]: time="2026-11-12T16:57:36Z" level=warning msg="Failed to load kernel module iptable_nat with modprobe"951machine # [ 21.367703] k3s[831]: time="2026-11-12T16:57:36Z" level=warning msg="Failed to load kernel module iptable_filter with modprobe"952machine # [ 21.376342] k3s[831]: time="2026-11-12T16:57:36Z" level=warning msg="Failed to load kernel module nft-expr-counter with modprobe"953machine # [ 21.432102] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Set sysctl 'net/ipv4/conf/all/forwarding' to 1"954machine # [ 21.434243] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 131072"955machine # [ 21.436414] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400"956machine # [ 21.438873] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600"957machine # [ 21.441273] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Creating k3s-cert-monitor event broadcaster"958machine # [ 21.446218] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"959machine # [ 21.450771] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Saving cluster bootstrap data to datastore"960machine # [ 21.456253] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"961machine # [ 21.458153] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Connection to etcd is ready"962machine # [ 21.459484] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="ETCD server is now running"963machine # [ 21.460905] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Handling backend connection request [machine]"964machine # [ 21.462401] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"965machine # [ 21.468238] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"966machine # [ 21.470061] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Polling for API server readiness: GET /readyz failed: the server is currently unable to handle the request"967machine # [ 21.472343] k3s[831]: time="2026-11-12T16:57:36Z" 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"968machine # [ 21.497670] k3s[831]: time="2026-11-12T16:57:36Z" 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"969machine # [ 21.505220] k3s[831]: time="2026-11-12T16:57:36Z" 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"970machine # [ 21.526253] k3s[831]: time="2026-11-12T16:57:36Z" 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"971machine # [ 21.536081] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Server node token is available at /var/lib/rancher/k3s/server/token"972machine # [ 21.546446] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="To join server node to cluster: k3s server -s https://10.0.2.15:6443 -t ${SERVER_NODE_TOKEN}"973machine # [ 21.548618] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Agent node token is available at /var/lib/rancher/k3s/server/agent-token"974machine # [ 21.550288] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="To join agent node to cluster: k3s agent -s https://10.0.2.15:6443 -t ${AGENT_NODE_TOKEN}"975machine # [ 21.553833] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"976machine # [ 21.555265] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Run: k3s kubectl"977machine # [ 21.556431] k3s[831]: I1112 16:57:36.232219 831 options.go:263] external host was not specified, using 10.0.2.15978machine # [ 21.557820] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log"979machine # [ 21.559515] k3s[831]: I1112 16:57:36.248848 831 server.go:158] Version: v1.36.5+k3s1980machine # [ 21.564214] k3s[831]: I1112 16:57:36.248921 831 server.go:160] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""981machine # [ 21.565752] k3s[831]: time="2026-11-12T16:57:36Z" level=info msg="Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml"982machine # [ 21.640029] k3s[831]: time="2026-11-12T16:57:36Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:51908: runtime core not ready"983machine # [ 21.796079] k3s[831]: time="2026-11-12T16:57:36Z" 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"984machine # [ 21.994911] k3s[831]: E1112 16:57:36.764122 831 options.go:205] The manifest file is empty, ignoring.985machine # [ 21.996781] k3s[831]: I1112 16:57:36.765825 831 shared_informer.go:381] "Waiting for caches to sync" controller="node_authorizer"986machine # [ 22.001900] k3s[831]: I1112 16:57:36.771222 831 shared_informer.go:402] "Waiting for caches to sync"987machine # [ 22.005804] k3s[831]: I1112 16:57:36.775123 831 shared_informer.go:402] "Waiting for caches to sync"988machine # [ 22.008843] k3s[831]: I1112 16:57:36.778183 831 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.989machine # [ 22.018643] k3s[831]: I1112 16:57:36.778220 831 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.990machine # [ 22.026216] k3s[831]: I1112 16:57:36.778659 831 instance.go:240] Using reconciler: lease991machine # [ 22.027676] k3s[831]: I1112 16:57:36.784616 831 handler.go:304] Adding GroupVersion apiextensions.k8s.io v1 to ResourceManager992machine # [ 22.029730] k3s[831]: W1112 16:57:36.784653 831 genericapiserver.go:798] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.993machine # [ 22.031847] k3s[831]: I1112 16:57:36.788473 831 cidrallocator.go:198] starting ServiceCIDR Allocator Controller994machine # [ 22.069923] k3s[831]: I1112 16:57:36.839204 831 handler.go:304] Adding GroupVersion v1 to ResourceManager995machine # [ 22.071692] k3s[831]: I1112 16:57:36.839511 831 apis.go:112] API group "internal.apiserver.k8s.io" is not enabled, skipping.996machine # [ 22.101399] k3s[831]: I1112 16:57:36.870617 831 apis.go:112] API group "storagemigration.k8s.io" is not enabled, skipping.997machine # [ 22.139829] k3s[831]: I1112 16:57:36.909077 831 handler.go:304] Adding GroupVersion authentication.k8s.io v1 to ResourceManager998machine # [ 22.144336] k3s[831]: W1112 16:57:36.909130 831 genericapiserver.go:798] Skipping API authentication.k8s.io/v1beta1 because it has no resources.999machine # [ 22.146937] k3s[831]: W1112 16:57:36.909142 831 genericapiserver.go:798] Skipping API authentication.k8s.io/v1alpha1 because it has no resources.1000machine # [ 22.152183] k3s[831]: I1112 16:57:36.910759 831 handler.go:304] Adding GroupVersion authorization.k8s.io v1 to ResourceManager1001machine # [ 22.153809] k3s[831]: W1112 16:57:36.910786 831 genericapiserver.go:798] Skipping API authorization.k8s.io/v1beta1 because it has no resources.1002machine # [ 22.155550] k3s[831]: I1112 16:57:36.919463 831 handler.go:304] Adding GroupVersion autoscaling v2 to ResourceManager1003machine # [ 22.160116] k3s[831]: I1112 16:57:36.920771 831 handler.go:304] Adding GroupVersion autoscaling v1 to ResourceManager1004machine # [ 22.161605] k3s[831]: I1112 16:57:36.927928 831 handler.go:304] Adding GroupVersion batch v1 to ResourceManager1005machine # [ 22.162975] k3s[831]: W1112 16:57:36.927956 831 genericapiserver.go:798] Skipping API batch/v1beta1 because it has no resources.1006machine # [ 22.165863] k3s[831]: I1112 16:57:36.929097 831 handler.go:304] Adding GroupVersion certificates.k8s.io v1 to ResourceManager1007machine # [ 22.167569] k3s[831]: W1112 16:57:36.929113 831 genericapiserver.go:798] Skipping API certificates.k8s.io/v1beta1 because it has no resources.1008machine # [ 22.169406] k3s[831]: W1112 16:57:36.929123 831 genericapiserver.go:798] Skipping API certificates.k8s.io/v1alpha1 because it has no resources.1009machine # [ 22.171223] k3s[831]: I1112 16:57:36.935343 831 handler.go:304] Adding GroupVersion coordination.k8s.io v1 to ResourceManager1010machine # [ 22.172819] k3s[831]: W1112 16:57:36.935374 831 genericapiserver.go:798] Skipping API coordination.k8s.io/v1beta1 because it has no resources.1011machine # [ 22.174517] k3s[831]: W1112 16:57:36.935385 831 genericapiserver.go:798] Skipping API coordination.k8s.io/v1alpha2 because it has no resources.1012machine # [ 22.176284] k3s[831]: I1112 16:57:36.936227 831 handler.go:304] Adding GroupVersion discovery.k8s.io v1 to ResourceManager1013machine # [ 22.177773] k3s[831]: W1112 16:57:36.936243 831 genericapiserver.go:798] Skipping API discovery.k8s.io/v1beta1 because it has no resources.1014machine # [ 22.179450] k3s[831]: I1112 16:57:36.939508 831 handler.go:304] Adding GroupVersion networking.k8s.io v1 to ResourceManager1015machine # [ 22.181049] k3s[831]: W1112 16:57:36.939534 831 genericapiserver.go:798] Skipping API networking.k8s.io/v1beta1 because it has no resources.1016machine # [ 22.182724] k3s[831]: I1112 16:57:36.940079 831 handler.go:304] Adding GroupVersion node.k8s.io v1 to ResourceManager1017machine # [ 22.188171] k3s[831]: W1112 16:57:36.940094 831 genericapiserver.go:798] Skipping API node.k8s.io/v1beta1 because it has no resources.1018machine # [ 22.189974] k3s[831]: W1112 16:57:36.940102 831 genericapiserver.go:798] Skipping API node.k8s.io/v1alpha1 because it has no resources.1019machine # [ 22.191650] k3s[831]: I1112 16:57:36.941059 831 handler.go:304] Adding GroupVersion policy v1 to ResourceManager1020machine # [ 22.193174] k3s[831]: W1112 16:57:36.941078 831 genericapiserver.go:798] Skipping API policy/v1beta1 because it has no resources.1021machine # [ 22.194975] k3s[831]: I1112 16:57:36.943252 831 handler.go:304] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager1022machine # [ 22.196686] k3s[831]: W1112 16:57:36.943275 831 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.1023machine # [ 22.198466] k3s[831]: W1112 16:57:36.943287 831 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.1024machine # [ 22.200294] k3s[831]: I1112 16:57:36.943780 831 handler.go:304] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager1025machine # [ 22.201817] k3s[831]: W1112 16:57:36.943804 831 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.1026machine # [ 22.203594] k3s[831]: W1112 16:57:36.943811 831 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1alpha2 because it has no resources.1027machine # [ 22.205468] k3s[831]: I1112 16:57:36.949801 831 handler.go:304] Adding GroupVersion storage.k8s.io v1 to ResourceManager1028machine # [ 22.206961] k3s[831]: W1112 16:57:36.949840 831 genericapiserver.go:798] Skipping API storage.k8s.io/v1beta1 because it has no resources.1029machine # [ 22.208684] k3s[831]: W1112 16:57:36.949851 831 genericapiserver.go:798] Skipping API storage.k8s.io/v1alpha1 because it has no resources.1030machine # [ 22.210344] k3s[831]: I1112 16:57:36.951083 831 handler.go:304] Adding GroupVersion flowcontrol.apiserver.k8s.io v1 to ResourceManager1031machine # [ 22.211958] k3s[831]: W1112 16:57:36.951104 831 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta3 because it has no resources.1032machine # [ 22.213933] k3s[831]: W1112 16:57:36.951111 831 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta2 because it has no resources.1033machine # [ 22.215822] k3s[831]: W1112 16:57:36.951116 831 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta1 because it has no resources.1034machine # [ 22.217812] k3s[831]: I1112 16:57:36.956737 831 handler.go:304] Adding GroupVersion apps v1 to ResourceManager1035machine # [ 22.219264] k3s[831]: W1112 16:57:36.956769 831 genericapiserver.go:798] Skipping API apps/v1beta2 because it has no resources.1036machine # [ 22.220913] k3s[831]: W1112 16:57:36.956779 831 genericapiserver.go:798] Skipping API apps/v1beta1 because it has no resources.1037machine # [ 22.222450] k3s[831]: I1112 16:57:36.960011 831 handler.go:304] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager1038machine # [ 22.224089] k3s[831]: W1112 16:57:36.960034 831 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.1039machine # [ 22.225921] k3s[831]: W1112 16:57:36.960044 831 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources.1040machine # [ 22.227799] k3s[831]: I1112 16:57:36.960600 831 handler.go:304] Adding GroupVersion events.k8s.io v1 to ResourceManager1041machine # [ 22.229395] k3s[831]: W1112 16:57:36.960613 831 genericapiserver.go:798] Skipping API events.k8s.io/v1beta1 because it has no resources.1042machine # [ 22.231071] k3s[831]: I1112 16:57:36.962667 831 handler.go:304] Adding GroupVersion resource.k8s.io v1 to ResourceManager1043machine # [ 22.232618] k3s[831]: W1112 16:57:36.962690 831 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta2 because it has no resources.1044machine # [ 22.234293] k3s[831]: W1112 16:57:36.962698 831 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta1 because it has no resources.1045machine # [ 22.236072] k3s[831]: W1112 16:57:36.962705 831 genericapiserver.go:798] Skipping API resource.k8s.io/v1alpha3 because it has no resources.1046machine # [ 22.237773] k3s[831]: I1112 16:57:36.967707 831 handler.go:304] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager1047machine # [ 22.239403] k3s[831]: W1112 16:57:36.967730 831 genericapiserver.go:798] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.1048machine # [ 22.527770] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="containerd is now running"1049machine # [ 22.538898] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/kyix6dphrkrxwz27rcspc3n86sqsafq8-k3s-airgap-images-arm64.tar.zst"1050machine # [ 22.819673] k3s[831]: I1112 16:57:37.589004 831 secure_serving.go:214] Serving securely on 127.0.0.1:64441051machine # [ 22.823060] k3s[831]: I1112 16:57:37.592429 831 local_available_controller.go:156] Starting LocalAvailability controller1052machine # [ 22.828219] k3s[831]: I1112 16:57:37.594310 831 cache.go:32] Waiting for caches to sync for LocalAvailability controller1053machine # [ 22.829773] k3s[831]: I1112 16:57:37.594374 831 remote_available_controller.go:434] Starting RemoteAvailability controller1054machine # [ 22.831338] k3s[831]: I1112 16:57:37.594394 831 cache.go:32] Waiting for caches to sync for RemoteAvailability controller1055machine # [ 22.835813] k3s[831]: I1112 16:57:37.594412 831 tlsconfig.go:243] "Starting DynamicServingCertificateController"1056machine # [ 22.837436] k3s[831]: I1112 16:57:37.592017 831 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1057machine # [ 22.839591] k3s[831]: I1112 16:57:37.594565 831 system_namespaces_controller.go:66] Starting system namespaces controller1058machine # [ 22.844175] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Starting apiserver lease garbage collector" logger=k3s1059machine # [ 22.845689] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Waiting for caches to sync" logger=k3s1060machine # [ 22.847054] k3s[831]: I1112 16:57:37.594843 831 storage_readiness_hook.go:70] Storage is ready for all registered resources1061machine # [ 22.852177] k3s[831]: I1112 16:57:37.594866 831 controller.go:113] "Deleting old lease on startup" lease="kube-system/apiserver-ik4pcwfs7qgdl76byc4pomgvia"1062machine # [ 22.854132] k3s[831]: I1112 16:57:37.595017 831 apiservice_controller.go:100] Starting APIServiceRegistrationController1063machine # [ 22.855678] k3s[831]: I1112 16:57:37.595031 831 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller1064machine # [ 22.857445] k3s[831]: I1112 16:57:37.595079 831 aggregator.go:185] waiting for initial CRD sync...1065machine # [ 22.858667] k3s[831]: I1112 16:57:37.595370 831 cluster_authentication_trust_controller.go:459] Starting cluster_authentication_trust_controller controller1066machine # [ 22.864189] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Waiting for caches to sync" logger=k3s1067machine # [ 22.865491] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Starting legacy_token_tracking_controller" logger=k3s1068machine # [ 22.866919] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Waiting for caches to sync" logger=k3s1069machine # [ 22.868248] k3s[831]: I1112 16:57:37.595575 831 apf_controller.go:377] Starting API Priority and Fairness config controller1070machine # [ 22.869748] k3s[831]: I1112 16:57:37.592043 831 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1071machine # [ 22.871839] k3s[831]: I1112 16:57:37.594078 831 customresource_discovery_controller.go:294] Starting DiscoveryController1072machine # [ 22.873750] k3s[831]: I1112 16:57:37.592514 831 controller.go:87] "Starting OpenAPI AggregationController"1073machine # [ 22.876092] k3s[831]: I1112 16:57:37.594371 831 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"1074machine # [ 22.878950] k3s[831]: I1112 16:57:37.602457 831 controller.go:142] Starting OpenAPI controller1075machine # [ 22.884180] k3s[831]: I1112 16:57:37.602976 831 controller.go:90] Starting OpenAPI V3 controller1076machine # [ 22.885453] k3s[831]: I1112 16:57:37.603000 831 naming_controller.go:305] Starting NamingConditionController1077machine # [ 22.886785] k3s[831]: I1112 16:57:37.603054 831 nonstructuralschema_controller.go:202] Starting NonStructuralSchemaConditionController1078machine # [ 22.888456] k3s[831]: I1112 16:57:37.603070 831 apiapproval_controller.go:196] Starting KubernetesAPIApprovalPolicyConformantConditionController1079machine # [ 22.890160] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Starting CRDFinalizer" logger=k3s1080machine # [ 22.891387] k3s[831]: I1112 16:57:37.603267 831 repairip.go:210] Starting ipallocator-repair-controller1081machine # [ 22.896193] k3s[831]: I1112 16:57:37.603282 831 shared_informer.go:381] "Waiting for caches to sync" controller="ipallocator-repair-controller"1082machine # [ 22.897955] k3s[831]: I1112 16:57:37.593194 831 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"1083machine # [ 22.900917] k3s[831]: I1112 16:57:37.593771 831 controller.go:89] "Starting OpenAPI V3 AggregationController"1084machine # [ 22.902251] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg=Starting controller=kubernetes-service-cidr-controller logger=k3s1085machine # [ 22.903785] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Waiting for caches to sync" logger=k3s1086machine # [ 22.908138] k3s[831]: I1112 16:57:37.604027 831 crdregistration_controller.go:114] Starting crd-autoregister controller1087machine # [ 22.909686] k3s[831]: I1112 16:57:37.604061 831 shared_informer.go:381] "Waiting for caches to sync" controller="crd-autoregister"1088machine # [ 22.911520] k3s[831]: I1112 16:57:37.604120 831 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1089machine # [ 22.913789] k3s[831]: I1112 16:57:37.604425 831 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1090machine # [ 23.028088] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Caches are synced" logger=k3s1091machine # [ 23.029502] k3s[831]: I1112 16:57:37.797268 831 cache.go:39] Caches are synced for LocalAvailability controller1092machine # [ 23.030971] k3s[831]: I1112 16:57:37.797336 831 cache.go:39] Caches are synced for APIServiceRegistrationController controller1093machine # [ 23.036282] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Caches are synced" logger=k3s1094machine # [ 23.037586] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Caches are synced" logger=k3s1095machine # [ 23.038721] k3s[831]: I1112 16:57:37.798103 831 apf_controller.go:382] Running API Priority and Fairness config worker1096machine # [ 23.044109] k3s[831]: I1112 16:57:37.798116 831 apf_controller.go:385] Running API Priority and Fairness periodic rebalancing process1097machine # [ 23.045772] k3s[831]: I1112 16:57:37.798298 831 handler_discovery.go:459] Starting ResourceDiscoveryManager1098machine # [ 23.047171] k3s[831]: I1112 16:57:37.803744 831 cache.go:39] Caches are synced for RemoteAvailability controller1099machine # [ 23.048617] k3s[831]: I1112 16:57:37.804144 831 shared_informer.go:388] "Caches are synced" controller="crd-autoregister"1100machine # [ 23.050082] k3s[831]: I1112 16:57:37.804247 831 aggregator.go:187] initial CRD sync complete...1101machine # [ 23.051404] k3s[831]: I1112 16:57:37.804275 831 autoregister_controller.go:144] Starting autoregister controller1102machine # [ 23.056108] k3s[831]: I1112 16:57:37.804284 831 cache.go:32] Waiting for caches to sync for autoregister controller1103machine # [ 23.057601] k3s[831]: I1112 16:57:37.804291 831 cache.go:39] Caches are synced for autoregister controller1104machine # [ 23.058956] k3s[831]: I1112 16:57:37.813198 831 shared_informer.go:388] "Caches are synced" controller="ipallocator-repair-controller"1105machine # [ 23.060659] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Caches are synced" logger=k3s1106machine # [ 23.061812] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Creating default ServiceCIDR" CIDRs="[10.43.0.0/16]" logger=k3s1107machine # [ 23.077392] k3s[831]: E1112 16:57:37.846491 831 controller.go:201] "Failed to ensure lease exists, will retry" err="namespaces \"kube-system\" not found" interval="200ms"1108machine # [ 23.086827] k3s[831]: E1112 16:57:37.855100 831 controller.go:95] Unable to perform initial Kubernetes service initialization: namespaces "default" not found1109machine # [ 23.088961] k3s[831]: time="2026-11-12T16:57:37Z" level=error msg="Error while syncing ConfigMap" configmap=kube-system/kube-apiserver-legacy-service-account-token-tracking error="namespaces \"kube-system\" not found" logger=k3s/UnhandledError1110machine # [ 23.096566] k3s[831]: I1112 16:57:37.865905 831 shared_informer.go:388] "Caches are synced" controller="node_authorizer"1111machine # [ 23.102307] k3s[831]: I1112 16:57:37.871470 831 shared_informer.go:409] "Caches are synced"1112machine # [ 23.103611] k3s[831]: I1112 16:57:37.871526 831 policy_source.go:248] refreshing policies1113machine # [ 23.108204] k3s[831]: I1112 16:57:37.875459 831 shared_informer.go:409] "Caches are synced"1114machine # [ 23.109387] k3s[831]: I1112 16:57:37.875520 831 policy_source.go:248] refreshing policies1115machine # [ 23.163793] k3s[831]: I1112 16:57:37.933105 831 cidrallocator.go:302] created ClusterIP allocator for Service CIDR 10.43.0.0/161116machine # [ 23.165909] k3s[831]: time="2026-11-12T16:57:37Z" level=info msg="Setting default ServiceCIDR condition Ready to True" logger=k3s1117machine # [ 23.180089] k3s[831]: I1112 16:57:37.947707 831 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161118machine # [ 23.281258] k3s[831]: I1112 16:57:38.050558 831 controller.go:667] quota admission added evaluator for: leases.coordination.k8s.io1119machine # [ 23.439750] k3s[831]: time="2026-11-12T16:57:38Z" level=info msg="Polling for API server readiness: GET /readyz failed: unknown"1120machine # [ 23.835598] k3s[831]: I1112 16:57:38.604333 831 storage_scheduling.go:137] created PriorityClass system-node-critical with value 20000010001121machine # [ 23.840079] k3s[831]: I1112 16:57:38.608680 831 storage_scheduling.go:137] created PriorityClass system-cluster-critical with value 20000000001122machine # [ 23.842042] k3s[831]: I1112 16:57:38.608709 831 storage_scheduling.go:153] all system priority classes are created successfully or already exist.1123machine # [ 24.368982] k3s[831]: I1112 16:57:39.137961 831 controller.go:667] quota admission added evaluator for: roles.rbac.authorization.k8s.io1124machine # [ 24.410607] k3s[831]: I1112 16:57:39.179926 831 controller.go:667] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io1125machine # [ 24.500124] k3s[831]: I1112 16:57:39.266392 831 alloc.go:329] "allocated clusterIPs" service="default/kubernetes" clusterIPs={"IPv4":"10.43.0.1"}1126machine # [ 24.504151] k3s[831]: W1112 16:57:39.272639 831 lease.go:265] Resetting endpoints for master service "kubernetes" to [10.0.2.15]1127machine # [ 24.505932] k3s[831]: I1112 16:57:39.274555 831 controller.go:667] quota admission added evaluator for: endpoints1128machine # [ 24.511657] k3s[831]: I1112 16:57:39.280574 831 controller.go:667] quota admission added evaluator for: endpointslices.discovery.k8s.io1129machine # [ 25.457712] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Waiting for untainted node"1130machine # [ 25.459127] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Kube API server is now running"1131machine # [ 25.460419] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="k3s is up and running"1132machine # [ 25.462590] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Creating k3s-supervisor event broadcaster"1133machine # [ 25.465204] systemd[1]: Started k3s service.1134machine # [ 25.465968] systemd[1]: Reached target Multi-User System.1135machine # [ 25.466759] systemd[1]: Startup finished in 814ms (kernel) + 3.651s (initrd) + 20.998s (userspace) = 25.464s.1136machine # [ 25.468473] k3s[831]: time="2026-11-12T16:57:40Z" 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=Normal1137machine # [ 25.510599] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Creating embedded CRD etcdsnapshotfiles.k3s.cattle.io"1138machine # [ 25.517001] k3s[831]: E1112 16:57:40.286343 831 options.go:205] The manifest file is empty, ignoring.1139machine # [ 25.522009] k3s[831]: I1112 16:57:40.291354 831 controllermanager.go:204] "Starting" version="v1.36.5+k3s1"1140machine # [ 25.527738] k3s[831]: I1112 16:57:40.297035 831 controllermanager.go:206] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1141machine # [ 25.536108] k3s[831]: I1112 16:57:40.304776 831 secure_serving.go:214] Serving securely on 127.0.0.1:102571142machine # [ 25.537516] k3s[831]: I1112 16:57:40.305294 831 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1143[26.29s] machine: (finished: waiting for unit k3s.service, in 26.29 seconds)1144machine # [ 25.538980] k3s[831]: I1112 16:57:40.305334 831 shared_informer.go:402] "Waiting for caches to sync"1145[26.29s] machine: waiting for unit rustfs-setup.service1146machine # [ 25.544318] k3s[831]: I1112 16:57:40.305372 831 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"1147machine # [ 25.547599] k3s[831]: I1112 16:57:40.305560 831 tlsconfig.go:243] "Starting DynamicServingCertificateController"1148machine # [ 25.550181] k3s[831]: I1112 16:57:40.305611 831 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1149machine # [ 25.555716] k3s[831]: I1112 16:57:40.305625 831 shared_informer.go:402] "Waiting for caches to sync"1150machine # [ 25.557546] k3s[831]: I1112 16:57:40.305639 831 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1151machine # [ 25.560675] k3s[831]: I1112 16:57:40.305653 831 shared_informer.go:402] "Waiting for caches to sync"1152machine # [ 25.563858] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Creating embedded CRD addons.k3s.cattle.io"1153machine # [ 25.582933] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Creating embedded CRD helmchartconfigs.helm.cattle.io"1154[26.36s] machine: (finished: waiting for unit rustfs-setup.service, in 0.06 seconds)1155[26.36s] machine: waiting for unit postgresql.service1156machine # [ 25.634547] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Creating embedded CRD helmcharts.helm.cattle.io"1157machine # [ 25.636563] k3s[831]: I1112 16:57:40.404394 831 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1158machine # [ 25.639674] k3s[831]: I1112 16:57:40.408956 831 controller.go:667] quota admission added evaluator for: serviceaccounts1159machine # [ 25.652420] k3s[831]: I1112 16:57:40.421500 831 shared_informer.go:409] "Caches are synced"1160machine # [ 25.653650] k3s[831]: I1112 16:57:40.421589 831 shared_informer.go:409] "Caches are synced"1161machine # [ 25.654791] k3s[831]: I1112 16:57:40.421670 831 shared_informer.go:409] "Caches are synced"1162[26.41s] machine: (finished: waiting for unit postgresql.service, in 0.05 seconds)1163[26.41s] subtest: chart deploys and becomes ready1164??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1165 File "/nix/store/81dgbf2d9k9llajgi9597ahypdjn5iam-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391166[26.41s] machine: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s1167??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1168 File "/nix/store/81dgbf2d9k9llajgi9597ahypdjn5iam-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391169machine # [ 25.695402] k3s[831]: I1112 16:57:40.464720 831 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1170machine # [ 25.718155] k3s[831]: I1112 16:57:40.487405 831 shared_informer.go:402] "Waiting for caches to sync"1171machine # [ 25.735782] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Waiting for CRD helmchartconfigs.helm.cattle.io to become available"1172machine # [ 25.748909] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Done waiting for CRD helmchartconfigs.helm.cattle.io to become available"1173machine # [ 25.750710] k3s[831]: time="2026-11-12T16:57:40Z" level=info msg="Waiting for CRD helmcharts.helm.cattle.io to become available"1174machine # [ 25.756225] k3s[831]: I1112 16:57:40.525577 831 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1175machine # [ 25.820763] k3s[831]: I1112 16:57:40.589984 831 shared_informer.go:409] "Caches are synced"1176machine # [ 25.898801] k3s[831]: I1112 16:57:40.668119 831 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1177machine # [ 25.953781] k3s[831]: I1112 16:57:40.722074 831 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podcertificaterequest-cleaner-controller" requiredFeatureGates=["PodCertificateRequest"]1178machine # [ 25.975291] k3s[831]: I1112 16:57:40.722159 831 controllermanager.go:641] "Warning: skipping controller" controller="podcertificaterequest-cleaner-controller"1179machine # [ 26.007203] k3s[831]: I1112 16:57:40.776465 831 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="storageversion-garbage-collector-controller" requiredFeatureGates=["APIServerIdentity","StorageVersionAPI"]1180machine # [ 26.010360] k3s[831]: I1112 16:57:40.779735 831 controllermanager.go:641] "Warning: skipping controller" controller="storageversion-garbage-collector-controller"1181machine # [ 26.043286] k3s[831]: I1112 16:57:40.812617 831 controllermanager.go:641] "Warning: skipping controller" controller="storage-version-migrator-controller"1182machine # Error from server (NotFound): namespaces "niks3" not found1183machine # [ 26.339481] k3s[831]: I1112 16:57:41.108800 831 controllermanager.go:689] "Warning: controller is disabled" controller="selinux-warning-controller"1184machine # [ 26.343206] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Done waiting for CRD helmcharts.helm.cattle.io to become available"1185machine # [ 26.345554] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-40.1.5+up40.1.0.tgz"1186machine # [ 26.352186] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-40.1.5+up40.1.0.tgz"1187machine # [ 26.354431] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml"1188machine # [ 26.356296] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml"1189machine # [ 26.358052] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml"1190machine # [ 26.359852] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml"1191machine # [ 26.361875] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/runtimes.yaml"1192machine # [ 26.364429] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml"1193machine # [ 26.366997] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Starting dynamiclistener CN filter node controller with SANs: [127.0.0.1 ::1 localhost machine 10.0.2.15 fec0::530:692a:a8f:b554 10.43.0.1 kubernetes kubernetes.default kubernetes.default.svc kubernetes.default.svc.cluster.local]"1194machine # [ 26.371066] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tunnel server egress proxy mode: agent"1195machine # [ 26.485144] k3s[831]: I1112 16:57:41.253788 831 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podgroup-protection-controller" requiredFeatureGates=["GenericWorkload"]1196machine # [ 26.487913] k3s[831]: I1112 16:57:41.253826 831 controllermanager.go:641] "Warning: skipping controller" controller="podgroup-protection-controller"1197machine # [ 26.490259] k3s[831]: I1112 16:57:41.253838 831 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller" requiredFeatureGates=["ClusterTrustBundle"]1198machine # [ 26.493959] k3s[831]: I1112 16:57:41.253847 831 controllermanager.go:641] "Warning: skipping controller" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller"1199machine # [ 26.496298] k3s[831]: I1112 16:57:41.253860 831 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="resourcepoolstatusrequest-controller" requiredFeatureGates=["DRAResourcePoolStatus"]1200machine # [ 26.499564] k3s[831]: I1112 16:57:41.253867 831 controllermanager.go:641] "Warning: skipping controller" controller="resourcepoolstatusrequest-controller"1201machine # [ 26.658947] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/klipper-helm:v0.13.3-build20260727"1202machine # [ 26.662267] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/klipper-helm@sha256:5425a2b4613d2458dbdff99218e8d487ebb59c20e7a941f061c0777070f0aac1"1203machine # [ 26.664691] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/klipper-lb:v0.4.17"1204machine # [ 26.668757] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/klipper-lb@sha256:910944bb0bd94f060a82a56ca1ea1c577d3e49b3473a093a47a985f32e92d94a"1205machine # [ 26.671269] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.37"1206machine # [ 26.673647] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/local-path-provisioner@sha256:e757967a5ec338f6a9b371c5a9688bedaa8c3578ea3dd4db329ea0084be0a86f"1207machine # [ 26.676325] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/mirrored-coredns-coredns:1.14.7"1208machine # [ 26.678161] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/mirrored-coredns-coredns@sha256:7efd3c635b03efd68c4e8398fc45f0d993d0e9ab016f72c1cefb0fd6d01aa286"1209machine # [ 26.683279] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/mirrored-library-busybox:1.37.0"1210machine # [ 26.686010] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/mirrored-library-busybox@sha256:101b4afd76732482eff9b95cae5f94bcf295e521fbec4e01b69c5421f3f3f3e5"1211machine # [ 26.688781] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/mirrored-library-traefik:3.7.13"1212machine # [ 26.691243] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/mirrored-library-traefik@sha256:f86a2cab1b5c649070c49f883c743dd32d8485a56e3368c5f93b9e91f1e91259"1213machine # [ 26.693986] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/mirrored-metrics-server:v0.9.0"1214machine # [ 26.695993] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/mirrored-metrics-server@sha256:d9862115e7c7881280d3d75ca26bda8ffc0fc213315979575bf23ce9826205c0"1215machine # [ 26.698545] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported docker.io/rancher/mirrored-pause:3.10.2"1216machine # [ 26.700262] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Tagged docker.io/rancher/mirrored-pause@sha256:f548e0e8e3dc1896ca956272154dde3314e8cc4fde0a57577ee9fa1c63f5baf4"1217machine # [ 26.848247] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Imported 8 images from /var/lib/rancher/k3s/agent/images/nixos/kyix6dphrkrxwz27rcspc3n86sqsafq8-k3s-airgap-images-arm64.tar.zst in 4.30979736s"1218machine # [ 26.851903] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/mlqw7365gm7qhg3p1ry5fbx09n7ydbhl-niks3-server.tar"1219machine # [ 26.931471] k3s[831]: time="2026-11-12T16:57:41Z" 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__530_692a_a8f_b554-478559:fec0::530:692a:a8f:b554 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=28C38227DE9755F8B959556DC552D71CA5E2D859]"1220machine # [ 26.945377] k3s[831]: I1112 16:57:41.714714 831 range_allocator.go:113] "No Secondary Service CIDR provided. Skipping filtering out secondary service addresses" logger="node-ipam-controller"1221machine # [ 26.949272] k3s[831]: I1112 16:57:41.714789 831 controllermanager.go:689] "Warning: controller is disabled" controller="cloud-node-lifecycle-controller"1222machine # [ 26.952057] k3s[831]: time="2026-11-12T16:57:41Z" level=info msg="Active TLS secret kube-system/k3s-serving (ver=239) (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__530_692a_a8f_b554-478559:fec0::530:692a:a8f:b554 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=28C38227DE9755F8B959556DC552D71CA5E2D859]"1223machine # [ 27.063799] k3s[831]: time="2026-11-12T16:57:41Z" 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::530:692a:a8f:b554 --node-labels= --read-only-port=0"1224machine # [ 27.069383] k3s[831]: 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 # [ 27.082065] k3s[831]: I1112 16:57:41.851169 831 server.go:541] "Kubelet version" kubeletVersion="v1.36.5+k3s1"1226machine # [ 27.087108] k3s[831]: I1112 16:57:41.853182 831 server.go:543] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1227machine # [ 27.088765] k3s[831]: I1112 16:57:41.853228 831 watchdog_linux.go:94] "Systemd watchdog is not enabled"1228machine # [ 27.090038] k3s[831]: I1112 16:57:41.853237 831 watchdog_linux.go:137] "Systemd watchdog is not enabled or the interval is invalid, so health checking will not be started."1229machine # [ 27.093000] k3s[831]: I1112 16:57:41.855614 831 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt"1230machine # [ 27.097156] k3s[831]: I1112 16:57:41.860540 831 server.go:1444] "Using cgroup driver setting received from the CRI runtime" cgroupDriver="systemd"1231machine # [ 27.103888] k3s[831]: I1112 16:57:41.873246 831 server.go:804] "--cgroups-per-qos enabled, but --cgroup-root was not specified. Defaulting to /"1232machine # [ 27.107003] k3s[831]: I1112 16:57:41.873290 831 server.go:865] "NoSwap is set due to memorySwapBehavior not specified" memorySwapBehavior="" FailSwapOn=false1233machine # [ 27.110230] k3s[831]: I1112 16:57:41.875042 831 container_manager_linux.go:273] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]1234machine # [ 27.113890] k3s[831]: I1112 16:57:41.875090 831 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 # [ 27.130082] k3s[831]: I1112 16:57:41.875375 831 topology_manager.go:172] "Creating topology manager with none policy"1236machine # [ 27.131567] k3s[831]: I1112 16:57:41.875391 831 container_manager_linux.go:309] "Creating device plugin manager"1237machine # [ 27.133668] k3s[831]: I1112 16:57:41.875572 831 container_manager_linux.go:318] "Creating Dynamic Resource Allocation (DRA) manager"1238machine # [ 27.135436] k3s[831]: I1112 16:57:41.880926 831 state_mem.go:45] "Initialized" logger="CPUManager state memory"1239machine # [ 27.136987] k3s[831]: I1112 16:57:41.881200 831 kubelet.go:485] "Attempting to sync node with API server"1240machine # [ 27.138354] k3s[831]: I1112 16:57:41.881248 831 kubelet.go:386] "Adding static pod path" path="/var/lib/rancher/k3s/agent/pod-manifests"1241machine # [ 27.140855] k3s[831]: I1112 16:57:41.881277 831 kubelet.go:397] "Adding apiserver pod source"1242machine # [ 27.142239] k3s[831]: I1112 16:57:41.881293 831 apiserver.go:41] "Waiting for node sync before watching apiserver pods"1243machine # [ 27.147684] k3s[831]: I1112 16:57:41.894859 831 kuberuntime_manager.go:308] "Container runtime initialized" containerRuntime="containerd" version="2.3.4-k3s1.36" apiVersion="v1"1244machine # [ 27.157631] k3s[831]: I1112 16:57:41.895921 831 kubelet.go:1002] "Not starting ClusterTrustBundle informer because we are in static kubelet mode or the ClusterTrustBundleProjection featuregate is disabled"1245machine # [ 27.164349] k3s[831]: I1112 16:57:41.895949 831 kubelet.go:1029] "Not starting PodCertificateRequest manager because we are in static kubelet mode or the PodCertificateProjection feature gate is disabled"1246machine # [ 27.172196] k3s[831]: W1112 16:57:41.896025 831 probe.go:275] Flexvolume plugin directory at /usr/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating.1247machine # [ 27.174288] k3s[831]: I1112 16:57:41.906219 831 server.go:1280] "Started kubelet"1248machine # [ 27.175354] k3s[831]: I1112 16:57:41.910979 831 fs_resource_analyzer.go:69] "Starting FS ResourceAnalyzer"1249machine # [ 27.184146] k3s[831]: I1112 16:57:41.920111 831 server.go:193] "Starting to listen" address="0.0.0.0" port=102501250machine # [ 27.185585] k3s[831]: I1112 16:57:41.921068 831 server.go:354] "Adding debug handlers to kubelet server"1251machine # [ 27.186905] k3s[831]: I1112 16:57:41.922381 831 ratelimit.go:56] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=101252machine # [ 27.192134] k3s[831]: I1112 16:57:41.922483 831 server_v1.go:49] "podresources" method="list" useActivePods=true1253machine # [ 27.193576] k3s[831]: I1112 16:57:41.922742 831 server.go:264] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock"1254machine # [ 27.195520] k3s[831]: I1112 16:57:41.922889 831 volume_manager.go:310] "Starting Kubelet Volume Manager"1255machine # [ 27.204165] k3s[831]: E1112 16:57:41.923152 831 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1256machine # [ 27.206380] k3s[831]: E1112 16:57:41.923426 831 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1257machine # [ 27.210187] k3s[831]: I1112 16:57:41.923495 831 desired_state_of_world_populator.go:146] "Desired state populator starts to run"1258machine # [ 27.215578] k3s[831]: I1112 16:57:41.923578 831 reconciler.go:29] "Reconciler: start to sync state"1259machine # [ 27.217093] k3s[831]: I1112 16:57:41.924080 831 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"1260machine # [ 27.219855] k3s[831]: I1112 16:57:41.924186 831 tlsconfig.go:243] "Starting DynamicServingCertificateController"1261machine # [ 27.227544] k3s[831]: E1112 16:57:41.932461 831 nodelease.go:50] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"machine\" not found" node="machine"1262machine # [ 27.232315] k3s[831]: E1112 16:57:41.946631 831 kubelet.go:1725] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"1263machine # [ 27.234701] k3s[831]: I1112 16:57:41.948619 831 factory.go:222] Registration of the containerd container factory successfully1264machine # [ 27.238959] k3s[831]: I1112 16:57:41.948641 831 factory.go:222] Registration of the systemd container factory successfully1265machine # [ 27.241439] k3s[831]: I1112 16:57:41.949243 831 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 directory1266machine # [ 27.245296] k3s[831]: I1112 16:57:41.974939 831 cpu_manager.go:235] "Starting" policy="none"1267machine # [ 27.246608] k3s[831]: I1112 16:57:41.974957 831 cpu_manager.go:236] "Reconciling" reconcilePeriod="10s"1268machine # [ 27.249319] k3s[831]: I1112 16:57:41.975005 831 state_mem.go:45] "Initialized" logger="CPUManager state checkpoint.CPUManager state memory"1269machine # [ 27.251065] k3s[831]: I1112 16:57:41.981644 831 policy_none.go:50] "Start"1270machine # [ 27.253126] k3s[831]: I1112 16:57:41.981697 831 memory_manager.go:190] "Starting memorymanager" policy="None"1271machine # [ 27.258211] k3s[831]: I1112 16:57:41.981719 831 state_mem.go:40] "Initializing new in-memory state store" logger="Memory Manager state checkpoint"1272machine # [ 27.260785] k3s[831]: I1112 16:57:41.987262 831 policy_none.go:44] "Start"1273machine # [ 27.263364] systemd[1]: Created slice libcontainer container kubepods.slice.1274machine # [ 27.266865] k3s[831]: E1112 16:57:42.034669 831 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found"1275machine # [ 27.268954] k3s[831]: E1112 16:57:42.034718 831 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1276machine # [ 27.279570] systemd[1]: Created slice libcontainer container kubepods-burstable.slice.1277machine # [ 27.291016] systemd[1]: Created slice libcontainer container kubepods-besteffort.slice.1278machine # [ 27.319772] k3s[831]: E1112 16:57:42.088425 831 manager.go:525] "Failed to read data from checkpoint" err="checkpoint is not found" checkpoint="kubelet_internal_checkpoint"1279machine # [ 27.323611] k3s[831]: I1112 16:57:42.088665 831 eviction_manager.go:194] "Eviction manager: starting control loop"1280machine # [ 27.331565] k3s[831]: I1112 16:57:42.088702 831 container_log_manager.go:146] "Initializing container log rotate workers" workers=1 monitorPeriod="10s"1281machine # [ 27.335174] k3s[831]: I1112 16:57:42.103990 831 plugin_manager.go:121] "Starting Kubelet Plugin Manager"1282machine # [ 27.339308] k3s[831]: E1112 16:57:42.108671 831 eviction_manager.go:272] "eviction manager: failed to check if we have separate container filesystem. Ignoring." err="no imagefs label for configured runtime"1283machine # [ 27.343769] k3s[831]: E1112 16:57:42.111341 831 eviction_manager.go:297] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"machine\" not found"1284machine # [ 27.356295] k3s[831]: E1112 16:57:42.125623 831 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1285machine # [ 27.425006] k3s[831]: I1112 16:57:42.193798 831 kubelet_node_status.go:75] "Attempting to register node" node="machine"1286machine # [ 27.458178] k3s[831]: E1112 16:57:42.227351 831 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine"1287machine # [ 27.465386] k3s[831]: I1112 16:57:42.229010 831 kubelet_node_status.go:78] "Successfully registered node" node="machine"1288machine # [ 27.466911] k3s[831]: E1112 16:57:42.229043 831 kubelet_node_status.go:479] "Error updating node status, will retry" err="error getting node \"machine\": node \"machine\" not found"1289machine # [ 27.470802] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Annotations and labels have been set successfully on node: machine"1290machine # Error from server (NotFound): namespaces "niks3" not found1291machine # [ 27.480222] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Starting flannel with backend vxlan"1292machine # [ 27.494911] k3s[831]: I1112 16:57:42.263568 831 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv4"1293machine # [ 27.504749] k3s[831]: I1112 16:57:42.274093 831 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv6"1294machine # [ 27.506358] k3s[831]: I1112 16:57:42.274136 831 status_manager.go:277] "Starting to sync pod status with apiserver"1295machine # [ 27.507933] k3s[831]: I1112 16:57:42.274182 831 kubelet.go:2622] "Starting kubelet main sync loop"1296machine # [ 27.509488] k3s[831]: E1112 16:57:42.274233 831 kubelet.go:2646] "Skipping pod synchronization" err="PLEG is not healthy: pleg has yet to be successful"1297machine # [ 27.511339] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller"1298machine # [ 27.516244] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Creating deploy event broadcaster"1299machine # [ 27.517523] k3s[831]: I1112 16:57:42.284510 831 controller.go:667] quota admission added evaluator for: addons.k3s.cattle.io1300machine # [ 27.537022] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Creating helm-controller event broadcaster"1301machine # [ 27.540455] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Starting /v1, Kind=Node controller"1302machine # [ 27.551352] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Registered handlers for helm-controller-chart-registration" logger=k3s/helm-controller1303machine # [ 27.566651] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Labels and annotations have been set successfully on node: machine"1304machine # [ 27.568627] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1305machine # [ 27.596078] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Cluster dns configmap has been set successfully"1306machine # [ 27.644313] k3s[831]: I1112 16:57:42.412731 831 kubelet_node_status.go:431] "Fast updating node status as it just became ready"1307machine # [ 27.709183] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1308machine # [ 27.722712] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1309machine # [ 27.750900] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1310machine # [ 27.765473] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1311machine # [ 27.784671] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Imported docker.io/library/niks3-server:1.17.1-aarch64-linux"1312machine # [ 27.787692] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Tagged docker.io/library/niks3-server@sha256:0ca36b133ae2d1d5f3cc4af3fac32cd6a72e369cfb91b5cb73b2248971415e86"1313machine # [ 27.814277] k3s[831]: time="2026-11-12T16:57:42Z" level=info msg="Imported 1 images from /var/lib/rancher/k3s/agent/images/nixos/mlqw7365gm7qhg3p1ry5fbx09n7ydbhl-niks3-server.tar in 962.49978ms"1314machine # [ 27.821407] k3s[831]: I1112 16:57:42.590744 831 server.go:228] "Successfully retrieved NodeIPs" NodeIPs=["10.0.2.15","fec0::530:692a:a8f:b554"]1315machine # [ 27.823501] k3s[831]: E1112 16:57:42.591485 831 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`"1316machine # [ 27.844605] k3s[831]: I1112 16:57:42.613915 831 server.go:274] "kube-proxy running in dual-stack mode" primary ipFamily="IPv4"1317machine # [ 27.846299] k3s[831]: I1112 16:57:42.613980 831 server_linux.go:137] "Using iptables Proxier"1318machine # [ 27.878011] k3s[831]: I1112 16:57:42.647298 831 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"1319machine # [ 27.890412] k3s[831]: I1112 16:57:42.659566 831 server.go:539] "Version info" version="v1.36.5+k3s1"1320machine # [ 27.891859] k3s[831]: I1112 16:57:42.659607 831 server.go:541] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1321machine # [ 27.898887] k3s[831]: I1112 16:57:42.668142 831 controller.go:667] quota admission added evaluator for: deployments.apps1322machine # [ 27.901995] k3s[831]: I1112 16:57:42.670624 831 config.go:200] "Starting service config controller"1323machine # [ 27.904312] k3s[831]: I1112 16:57:42.671227 831 shared_informer.go:381] "Waiting for caches to sync" controller="service config"1324machine # [ 27.906924] k3s[831]: I1112 16:57:42.671788 831 config.go:106] "Starting endpoint slice config controller"1325machine # [ 27.909507] k3s[831]: I1112 16:57:42.671809 831 shared_informer.go:381] "Waiting for caches to sync" controller="endpoint slice config"1326machine # [ 27.911251] k3s[831]: I1112 16:57:42.671824 831 config.go:403] "Starting serviceCIDR config controller"1327machine # [ 27.912659] k3s[831]: I1112 16:57:42.671839 831 shared_informer.go:381] "Waiting for caches to sync" controller="serviceCIDR config"1328machine # [ 27.914331] k3s[831]: I1112 16:57:42.672574 831 config.go:309] "Starting node config controller"1329machine # [ 27.915623] k3s[831]: I1112 16:57:42.672589 831 shared_informer.go:381] "Waiting for caches to sync" controller="node config"1330machine # [ 27.917405] k3s[831]: I1112 16:57:42.672599 831 shared_informer.go:388] "Caches are synced" controller="node config"1331machine # [ 28.003497] k3s[831]: I1112 16:57:42.772701 831 shared_informer.go:388] "Caches are synced" controller="serviceCIDR config"1332machine # [ 28.006111] k3s[831]: I1112 16:57:42.772739 831 shared_informer.go:388] "Caches are synced" controller="service config"1333machine # [ 28.008569] k3s[831]: I1112 16:57:42.772754 831 shared_informer.go:388] "Caches are synced" controller="endpoint slice config"1334machine # [ 28.028123] k3s[831]: I1112 16:57:42.797008 831 alloc.go:329] "allocated clusterIPs" service="kube-system/kube-dns" clusterIPs={"IPv4":"10.43.0.10"}1335machine # [ 28.036172] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1336machine # [ 28.059687] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1337machine # [ 28.075709] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1338machine # [ 28.086670] k3s[831]: I1112 16:57:42.856002 831 controller.go:667] quota admission added evaluator for: helmcharts.helm.cattle.io1339machine # [ 28.092240] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1340machine # [ 28.104091] k3s[831]: time="2026-11-12T16:57:42Z" 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=Normal1341machine # [ 28.118565] k3s[831]: I1112 16:57:42.885388 831 apiserver.go:51] "Watching apiserver"1342machine # [ 28.154350] k3s[831]: I1112 16:57:42.923703 831 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world"1343machine # [ 28.282052] k3s[831]: time="2026-11-12T16:57:43Z" 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=Normal1344machine # [ 28.297537] k3s[831]: time="2026-11-12T16:57:43Z" 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=Normal1345machine # [ 28.451561] k3s[831]: time="2026-11-12T16:57:43Z" 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=Normal1346machine # [ 28.468191] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Tunnel authorizer set Kubelet Port 0.0.0.0:10250"1347machine # [ 28.615692] k3s[831]: I1112 16:57:43.383652 831 serving.go:417] Generated self-signed cert in-memory1348machine # [ 28.655258] k3s[831]: time="2026-11-12T16:57:43Z" 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=Normal1349machine # [ 28.668139] k3s[831]: I1112 16:57:43.436314 831 node_lifecycle_controller.go:402] "Controller will reconcile labels" logger="node-lifecycle-controller"1350machine # [ 28.686005] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller"1351machine # [ 28.693380] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting batch/v1, Kind=Job controller"1352machine # [ 28.694807] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting /v1, Kind=Secret controller"1353machine # [ 28.697806] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting /v1, Kind=ConfigMap controller"1354machine # [ 28.699145] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting /v1, Kind=ServiceAccount controller"1355machine # [ 28.706214] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller"1356machine # [ 28.707745] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller"1357machine # [ 28.743225] k3s[831]: time="2026-11-12T16:57:43Z" 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=Normal1358machine # Error from server (NotFound): namespaces "niks3" not found1359machine # [ 28.801315] k3s[831]: I1112 16:57:43.570625 831 controller.go:667] quota admission added evaluator for: jobs.batch1360machine # [ 28.826207] k3s[831]: I1112 16:57:43.595521 831 serving.go:417] Generated self-signed cert in-memory1361machine # [ 28.941626] k3s[831]: I1112 16:57:43.710803 831 controllermanager.go:163] Version: v1.36.5+k3s11362machine # [ 28.947467] k3s[831]: I1112 16:57:43.716799 831 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1363machine # [ 28.952213] k3s[831]: I1112 16:57:43.717359 831 tlsconfig.go:243] "Starting DynamicServingCertificateController"1364machine # [ 28.954458] k3s[831]: I1112 16:57:43.717385 831 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1365machine # [ 28.963867] k3s[831]: I1112 16:57:43.719600 831 shared_informer.go:402] "Waiting for caches to sync"1366machine # [ 28.966095] k3s[831]: I1112 16:57:43.717397 831 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1367machine # [ 28.969810] k3s[831]: I1112 16:57:43.719635 831 shared_informer.go:402] "Waiting for caches to sync"1368machine # [ 28.971796] k3s[831]: I1112 16:57:43.719514 831 shared_informer.go:402] "Waiting for caches to sync"1369machine # [ 28.973703] k3s[831]: I1112 16:57:43.717335 831 secure_serving.go:214] Serving securely on 127.0.0.1:102581370machine # [ 28.975630] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Creating service-lb-controller event broadcaster"1371machine # [ 29.052132] k3s[831]: I1112 16:57:43.820685 831 shared_informer.go:409] "Caches are synced"1372machine # [ 29.054099] k3s[831]: I1112 16:57:43.820735 831 shared_informer.go:409] "Caches are synced"1373machine # [ 29.055978] k3s[831]: I1112 16:57:43.820855 831 shared_informer.go:409] "Caches are synced"1374machine # [ 29.186906] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting /v1, Kind=Node controller"1375machine # [ 29.194490] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting /v1, Kind=Pod controller"1376machine # [ 29.202924] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller"1377machine # [ 29.215642] k3s[831]: I1112 16:57:43.984956 831 controllermanager.go:338] Started "cloud-node-controller"1378machine # [ 29.220176] k3s[831]: I1112 16:57:43.985368 831 controllermanager.go:338] Started "cloud-node-lifecycle-controller"1379machine # [ 29.222421] k3s[831]: I1112 16:57:43.988246 831 controllermanager.go:338] Started "service-lb-controller"1380machine # [ 29.227096] k3s[831]: W1112 16:57:43.988275 831 controllermanager.go:315] "node-route-controller" is disabled1381machine # [ 29.232195] k3s[831]: time="2026-11-12T16:57:43Z" level=info msg="Starting discovery.k8s.io/v1, Kind=EndpointSlice controller"1382machine # [ 29.234608] k3s[831]: I1112 16:57:43.989559 831 node_controller.go:179] Sending events to api server.1383machine # [ 29.240205] k3s[831]: I1112 16:57:43.989636 831 node_lifecycle_controller.go:112] Sending events to api server1384machine # [ 29.242291] k3s[831]: I1112 16:57:43.989845 831 node_controller.go:188] Waiting for informer caches to sync1385machine # [ 29.248160] k3s[831]: I1112 16:57:43.989977 831 controller.go:235] Starting service controller1386machine # [ 29.249843] k3s[831]: I1112 16:57:43.990004 831 shared_informer.go:402] "Waiting for caches to sync"1387machine # [ 29.251590] k3s[831]: I1112 16:57:44.010597 831 controllermanager.go:689] "Warning: controller is disabled" controller="bootstrap-signer-controller"1388machine # [ 29.256160] k3s[831]: I1112 16:57:44.010623 831 controllermanager.go:689] "Warning: controller is disabled" controller="service-lb-controller"1389machine # [ 29.258370] k3s[831]: I1112 16:57:44.010631 831 controllermanager.go:689] "Warning: controller is disabled" controller="node-route-controller"1390machine # [ 29.323870] k3s[831]: I1112 16:57:44.093108 831 shared_informer.go:409] "Caches are synced"1391machine # [ 29.325375] k3s[831]: I1112 16:57:44.093169 831 node_controller.go:432] Initializing node machine with cloud provider1392machine # [ 29.346655] k3s[831]: time="2026-11-12T16:57:44Z" level=info msg="Synced coredns NodeHosts entries for machine"1393machine # [ 29.352188] k3s[831]: E1112 16:57:44.117814 831 options.go:205] The manifest file is empty, ignoring.1394machine # [ 29.353531] k3s[831]: I1112 16:57:44.120039 831 node_controller.go:477] Successfully initialized node machine with cloud provider1395machine # [ 29.355141] k3s[831]: I1112 16:57:44.120412 831 event.go:389] "Event occurred" object="machine" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="Synced" message="Node synced successfully"1396machine # [ 29.360153] k3s[831]: I1112 16:57:44.124248 831 server.go:176] "Starting Kubernetes Scheduler" version="v1.36.5+k3s1"1397machine # [ 29.361657] k3s[831]: I1112 16:57:44.124277 831 server.go:178] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1398machine # [ 29.363104] k3s[831]: I1112 16:57:44.128213 831 secure_serving.go:214] Serving securely on 127.0.0.1:102591399machine # [ 29.367761] k3s[831]: I1112 16:57:44.128353 831 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1400machine # [ 29.369470] k3s[831]: I1112 16:57:44.128372 831 shared_informer.go:402] "Waiting for caches to sync"1401machine # [ 29.370716] k3s[831]: I1112 16:57:44.128409 831 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"1402machine # [ 29.377552] k3s[831]: I1112 16:57:44.128525 831 tlsconfig.go:243] "Starting DynamicServingCertificateController"1403machine # [ 29.379070] k3s[831]: I1112 16:57:44.130563 831 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1404machine # [ 29.383978] k3s[831]: I1112 16:57:44.130586 831 shared_informer.go:402] "Waiting for caches to sync"1405machine # [ 29.385311] k3s[831]: I1112 16:57:44.130605 831 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1406machine # [ 29.387638] k3s[831]: I1112 16:57:44.130619 831 shared_informer.go:402] "Waiting for caches to sync"1407machine # [ 29.459285] k3s[831]: I1112 16:57:44.228461 831 shared_informer.go:409] "Caches are synced"1408machine # [ 29.461448] k3s[831]: I1112 16:57:44.230676 831 shared_informer.go:409] "Caches are synced"1409machine # [ 29.463374] k3s[831]: I1112 16:57:44.230742 831 shared_informer.go:409] "Caches are synced"1410machine # [ 29.693774] k3s[831]: I1112 16:57:44.462396 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="cronjobs.batch"1411machine # [ 29.697677] k3s[831]: I1112 16:57:44.462489 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="ingresses.networking.k8s.io"1412machine # [ 29.701424] k3s[831]: I1112 16:57:44.462534 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="csistoragecapacities.storage.k8s.io"1413machine # [ 29.705311] k3s[831]: I1112 16:57:44.462579 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmcharts.helm.cattle.io"1414machine # [ 29.708937] k3s[831]: I1112 16:57:44.462609 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="addons.k3s.cattle.io"1415machine # [ 29.712496] k3s[831]: I1112 16:57:44.462674 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="networkpolicies.networking.k8s.io"1416machine # [ 29.716184] k3s[831]: I1112 16:57:44.462712 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="podtemplates"1417machine # [ 29.719588] k3s[831]: I1112 16:57:44.462742 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="rolebindings.rbac.authorization.k8s.io"1418machine # [ 29.724682] k3s[831]: I1112 16:57:44.462770 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpoints"1419machine # [ 29.727977] k3s[831]: I1112 16:57:44.462814 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="deployments.apps"1420machine # [ 29.731422] k3s[831]: I1112 16:57:44.462842 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmchartconfigs.helm.cattle.io"1421machine # [ 29.735349] k3s[831]: I1112 16:57:44.462874 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="limitranges"1422machine # [ 29.738861] k3s[831]: I1112 16:57:44.463028 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="daemonsets.apps"1423machine # [ 29.742395] k3s[831]: I1112 16:57:44.463057 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="replicasets.apps"1424machine # [ 29.745858] k3s[831]: I1112 16:57:44.463096 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="leases.coordination.k8s.io"1425machine # [ 29.749232] k3s[831]: I1112 16:57:44.463124 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="serviceaccounts"1426machine # [ 29.752308] k3s[831]: I1112 16:57:44.463157 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="statefulsets.apps"1427machine # [ 29.755265] k3s[831]: I1112 16:57:44.463186 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="controllerrevisions.apps"1428machine # [ 29.758398] k3s[831]: I1112 16:57:44.463212 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="horizontalpodautoscalers.autoscaling"1429machine # [ 29.761598] k3s[831]: I1112 16:57:44.463241 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="poddisruptionbudgets.policy"1430machine # [ 29.764488] k3s[831]: I1112 16:57:44.463287 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpointslices.discovery.k8s.io"1431machine # [ 29.767356] k3s[831]: I1112 16:57:44.463337 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="resourceclaimtemplates.resource.k8s.io"1432machine # [ 29.770392] k3s[831]: I1112 16:57:44.463393 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="jobs.batch"1433machine # [ 29.772883] k3s[831]: I1112 16:57:44.463431 831 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="roles.rbac.authorization.k8s.io"1434machine # Error from server (NotFound): namespaces "niks3" not found1435machine # [ 30.291884] k3s[831]: I1112 16:57:45.061137 831 controller.go:753] "Starting resource claim controller"1436machine # [ 30.300342] k3s[831]: I1112 16:57:45.063622 831 shared_informer.go:402] "Waiting for caches to sync"1437machine # [ 30.302441] k3s[831]: I1112 16:57:45.068861 831 shared_informer.go:402] "Waiting for caches to sync"1438machine # [ 30.304477] k3s[831]: I1112 16:57:45.068947 831 legacy_serviceaccount_token_cleaner.go:103] "Starting legacy service account token cleaner controller"1439machine # [ 30.312278] k3s[831]: I1112 16:57:45.068966 831 shared_informer.go:402] "Waiting for caches to sync"1440machine # [ 30.314364] k3s[831]: I1112 16:57:45.068997 831 taint_eviction.go:283] "Starting" controller="taint-eviction-controller"1441machine # [ 30.320140] k3s[831]: I1112 16:57:45.069063 831 taint_eviction.go:288] "Sending events to API server"1442machine # [ 30.322182] k3s[831]: I1112 16:57:45.069075 831 shared_informer.go:402] "Waiting for caches to sync"1443machine # [ 30.327640] k3s[831]: I1112 16:57:45.069144 831 endpoints_controller.go:193] "Starting endpoint controller"1444machine # [ 30.330078] k3s[831]: I1112 16:57:45.069160 831 shared_informer.go:402] "Waiting for caches to sync"1445machine # [ 30.336252] k3s[831]: I1112 16:57:45.069219 831 endpointslice_controller.go:280] "Starting endpoint slice controller"1446machine # [ 30.338436] k3s[831]: I1112 16:57:45.069237 831 shared_informer.go:402] "Waiting for caches to sync"1447machine # [ 30.343112] k3s[831]: I1112 16:57:45.069307 831 job_controller.go:336] "Starting job controller"1448machine # [ 30.345098] k3s[831]: I1112 16:57:45.069325 831 shared_informer.go:402] "Waiting for caches to sync"1449machine # [ 30.346996] k3s[831]: I1112 16:57:45.069364 831 vac_protection_controller.go:206] "Starting VAC protection controller"1450machine # [ 30.352174] k3s[831]: I1112 16:57:45.069379 831 shared_informer.go:402] "Waiting for caches to sync"1451machine # [ 30.354241] k3s[831]: I1112 16:57:45.076758 831 ttlafterfinished_controller.go:112] "Starting TTL after finished controller"1452machine # [ 30.359417] k3s[831]: I1112 16:57:45.076820 831 shared_informer.go:402] "Waiting for caches to sync"1453machine # [ 30.361375] k3s[831]: I1112 16:57:45.076970 831 servicecidrs_controller.go:137] "Starting" controller="service-cidr-controller"1454machine # [ 30.363488] k3s[831]: I1112 16:57:45.076991 831 shared_informer.go:402] "Waiting for caches to sync"1455machine # [ 30.368085] k3s[831]: I1112 16:57:45.077042 831 device_taint_eviction.go:783] "Starting" controller="device-taint-eviction-controller" numWorkers=81456machine # [ 30.370301] k3s[831]: I1112 16:57:45.077449 831 disruption.go:453] "Sending events to api server."1457machine # [ 30.376136] k3s[831]: I1112 16:57:45.077495 831 disruption.go:460] "Starting disruption controller"1458machine # [ 30.377668] k3s[831]: I1112 16:57:45.077507 831 shared_informer.go:402] "Waiting for caches to sync"1459machine # [ 30.379156] k3s[831]: I1112 16:57:45.077535 831 clusterroleaggregation_controller.go:176] "Starting ClusterRoleAggregator controller"1460machine # [ 30.382044] k3s[831]: I1112 16:57:45.077550 831 shared_informer.go:402] "Waiting for caches to sync"1461machine # [ 30.383501] k3s[831]: I1112 16:57:45.077588 831 pv_protection_controller.go:81] "Starting PV protection controller"1462machine # [ 30.388093] k3s[831]: I1112 16:57:45.077604 831 shared_informer.go:402] "Waiting for caches to sync"1463machine # [ 30.389492] k3s[831]: I1112 16:57:45.077631 831 publisher.go:107] "Starting root CA cert publisher controller"1464machine # [ 30.391009] k3s[831]: I1112 16:57:45.077646 831 shared_informer.go:402] "Waiting for caches to sync"1465machine # [ 30.395317] k3s[831]: I1112 16:57:45.077736 831 daemon_controller.go:364] "Starting daemon sets controller"1466machine # [ 30.396821] k3s[831]: I1112 16:57:45.077752 831 shared_informer.go:402] "Waiting for caches to sync"1467machine # [ 30.398113] k3s[831]: I1112 16:57:45.077780 831 gc_controller.go:98] "Starting GC controller"1468machine # [ 30.399320] k3s[831]: I1112 16:57:45.077797 831 shared_informer.go:402] "Waiting for caches to sync"1469machine # [ 30.404165] k3s[831]: I1112 16:57:45.077861 831 deployment_controller.go:180] "Starting controller" controller="deployment"1470machine # [ 30.405743] k3s[831]: I1112 16:57:45.077878 831 shared_informer.go:402] "Waiting for caches to sync"1471machine # [ 30.407020] k3s[831]: I1112 16:57:45.077976 831 node_ipam_controller.go:142] "Starting ipam controller"1472machine # [ 30.408372] k3s[831]: I1112 16:57:45.077994 831 shared_informer.go:402] "Waiting for caches to sync"1473machine # [ 30.409642] k3s[831]: I1112 16:57:45.078027 831 expand_controller.go:328] "Starting expand controller"1474machine # [ 30.411019] k3s[831]: I1112 16:57:45.078043 831 shared_informer.go:402] "Waiting for caches to sync"1475machine # [ 30.412348] k3s[831]: I1112 16:57:45.078068 831 pvc_protection_controller.go:172] "Starting PVC protection controller"1476machine # [ 30.413805] k3s[831]: I1112 16:57:45.078082 831 shared_informer.go:402] "Waiting for caches to sync"1477machine # [ 30.415128] k3s[831]: I1112 16:57:45.078104 831 shared_informer.go:402] "Waiting for caches to sync"1478machine # [ 30.416429] k3s[831]: I1112 16:57:45.078170 831 replica_set.go:285] "Starting controller" name="replicationcontroller"1479machine # [ 30.417872] k3s[831]: I1112 16:57:45.078185 831 shared_informer.go:402] "Waiting for caches to sync"1480machine # [ 30.419124] k3s[831]: I1112 16:57:45.078212 831 serviceaccounts_controller.go:117] "Starting service account controller"1481machine # [ 30.420649] k3s[831]: I1112 16:57:45.078228 831 shared_informer.go:402] "Waiting for caches to sync"1482machine # [ 30.422059] k3s[831]: I1112 16:57:45.078281 831 stateful_set.go:234] "Starting stateful set controller"1483machine # [ 30.423356] k3s[831]: I1112 16:57:45.078295 831 shared_informer.go:402] "Waiting for caches to sync"1484machine # [ 30.424653] k3s[831]: I1112 16:57:45.078355 831 cronjob_controllerv2.go:143] "Starting cronjob controller v2"1485machine # [ 30.425974] k3s[831]: I1112 16:57:45.078370 831 shared_informer.go:402] "Waiting for caches to sync"1486machine # [ 30.427217] k3s[831]: I1112 16:57:45.078410 831 cleaner.go:83] "Starting CSR cleaner controller"1487machine # [ 30.428457] k3s[831]: I1112 16:57:45.078470 831 ttl_controller.go:127] "Starting TTL controller"1488machine # [ 30.429642] k3s[831]: I1112 16:57:45.078486 831 shared_informer.go:402] "Waiting for caches to sync"1489machine # [ 30.430883] k3s[831]: I1112 16:57:45.078510 831 tokencleaner.go:117] "Starting token cleaner controller"1490machine # [ 30.432213] k3s[831]: I1112 16:57:45.078524 831 shared_informer.go:402] "Waiting for caches to sync"1491machine # [ 30.433447] k3s[831]: I1112 16:57:45.078566 831 node_lifecycle_controller.go:436] "Sending events to api server"1492machine # [ 30.434821] k3s[831]: I1112 16:57:45.078593 831 node_lifecycle_controller.go:443] "Starting node controller"1493machine # [ 30.436169] k3s[831]: I1112 16:57:45.078602 831 shared_informer.go:402] "Waiting for caches to sync"1494machine # [ 30.437425] k3s[831]: I1112 16:57:45.078628 831 namespace_controller.go:202] "Starting namespace controller"1495machine # [ 30.438755] k3s[831]: I1112 16:57:45.078644 831 shared_informer.go:402] "Waiting for caches to sync"1496machine # [ 30.440024] k3s[831]: I1112 16:57:45.078707 831 replica_set.go:285] "Starting controller" name="replicaset"1497machine # [ 30.441345] k3s[831]: I1112 16:57:45.078725 831 shared_informer.go:402] "Waiting for caches to sync"1498machine # [ 30.442674] k3s[831]: I1112 16:57:45.078754 831 horizontal.go:204] "Starting HPA controller"1499machine # [ 30.443864] k3s[831]: I1112 16:57:45.078788 831 shared_informer.go:402] "Waiting for caches to sync"1500machine # [ 30.445221] k3s[831]: I1112 16:57:45.078828 831 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-legacy-unknown"1501machine # [ 30.446994] k3s[831]: I1112 16:57:45.078843 831 shared_informer.go:402] "Waiting for caches to sync"1502machine # [ 30.448289] k3s[831]: I1112 16:57:45.078868 831 certificate_controller.go:120] "Starting certificate controller" name="csrapproving"1503machine # [ 30.449873] k3s[831]: I1112 16:57:45.078882 831 shared_informer.go:402] "Waiting for caches to sync"1504machine # [ 30.451136] k3s[831]: I1112 16:57:45.078942 831 endpointslicemirroring_controller.go:226] "Starting EndpointSliceMirroring controller"1505machine # [ 30.452842] k3s[831]: I1112 16:57:45.078960 831 shared_informer.go:402] "Waiting for caches to sync"1506machine # [ 30.454092] k3s[831]: I1112 16:57:45.079260 831 pv_controller_base.go:318] "Starting persistent volume controller"1507machine # [ 30.455568] k3s[831]: I1112 16:57:45.079278 831 shared_informer.go:402] "Waiting for caches to sync"1508machine # [ 30.456995] k3s[831]: I1112 16:57:45.079336 831 attach_detach_controller.go:334] "Starting attach detach controller"1509machine # [ 30.458434] k3s[831]: I1112 16:57:45.079351 831 shared_informer.go:402] "Waiting for caches to sync"1510machine # [ 30.459706] k3s[831]: I1112 16:57:45.079375 831 controller.go:174] "Starting ephemeral volume controller"1511machine # [ 30.461150] k3s[831]: I1112 16:57:45.079390 831 shared_informer.go:402] "Waiting for caches to sync"1512machine # [ 30.462406] k3s[831]: I1112 16:57:45.080977 831 device_taint_eviction.go:823] "Sending events to api server"1513machine # [ 30.463892] k3s[831]: I1112 16:57:45.081099 831 device_taint_eviction.go:1023] "Waiting" for="cache and event handler sync"1514machine # [ 30.465545] k3s[831]: I1112 16:57:45.081177 831 garbagecollector.go:141] "Starting controller" controller="garbagecollector"1515machine # [ 30.467051] k3s[831]: I1112 16:57:45.081201 831 shared_informer.go:402] "Waiting for caches to sync"1516machine # [ 30.468326] k3s[831]: I1112 16:57:45.081297 831 graph_builder.go:387] "Running" component="GraphBuilder"1517machine # [ 30.469609] k3s[831]: I1112 16:57:45.081346 831 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-serving"1518machine # [ 30.471347] k3s[831]: I1112 16:57:45.081360 831 shared_informer.go:402] "Waiting for caches to sync"1519machine # [ 30.472655] k3s[831]: I1112 16:57:45.081393 831 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-client"1520machine # [ 30.474471] k3s[831]: I1112 16:57:45.081407 831 shared_informer.go:402] "Waiting for caches to sync"1521machine # [ 30.475743] k3s[831]: I1112 16:57:45.086231 831 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kube-apiserver-client"1522machine # [ 30.477726] k3s[831]: I1112 16:57:45.086268 831 shared_informer.go:402] "Waiting for caches to sync"1523machine # [ 30.478981] k3s[831]: I1112 16:57:45.086298 831 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"1524machine # [ 30.481728] k3s[831]: I1112 16:57:45.086486 831 resource_quota_controller.go:297] "Starting resource quota controller"1525machine # [ 30.483259] k3s[831]: I1112 16:57:45.086513 831 shared_informer.go:402] "Waiting for caches to sync"1526machine # [ 30.484684] k3s[831]: I1112 16:57:45.086564 831 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"1527machine # [ 30.487434] k3s[831]: I1112 16:57:45.086655 831 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"1528machine # [ 30.490384] k3s[831]: I1112 16:57:45.086758 831 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"1529machine # [ 30.493345] k3s[831]: I1112 16:57:45.087222 831 resource_quota_monitor.go:309] "QuotaMonitor running"1530machine # [ 30.494787] k3s[831]: I1112 16:57:45.122743 831 shared_informer.go:402] "Waiting for caches to sync"1531machine # [ 30.496135] k3s[831]: I1112 16:57:45.137556 831 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceClaim"1532machine # [ 30.498311] k3s[831]: I1112 16:57:45.137587 831 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"1533machine # [ 30.501580] k3s[831]: I1112 16:57:45.137858 831 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"1534machine # [ 30.505213] k3s[831]: I1112 16:57:45.147129 831 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"1535machine # [ 30.508328] k3s[831]: I1112 16:57:45.147203 831 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceSlice"1536machine # [ 30.510383] k3s[831]: I1112 16:57:45.149152 831 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.DeviceClass"1537machine # [ 30.512455] k3s[831]: I1112 16:57:45.149378 831 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.Pod"1538machine # [ 30.514488] k3s[831]: I1112 16:57:45.149393 831 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"1539machine # [ 30.517715] k3s[831]: I1112 16:57:45.163592 831 shared_informer.go:402] "Waiting for caches to sync"1540machine # [ 30.519127] k3s[831]: I1112 16:57:45.170858 831 shared_informer.go:409] "Caches are synced"1541machine # [ 30.520476] k3s[831]: I1112 16:57:45.170967 831 shared_informer.go:409] "Caches are synced"1542machine # [ 30.521763] k3s[831]: I1112 16:57:45.171001 831 shared_informer.go:409] "Caches are synced"1543machine # [ 30.523068] k3s[831]: I1112 16:57:45.171146 831 shared_informer.go:409] "Caches are synced"1544machine # [ 30.524442] k3s[831]: I1112 16:57:45.171197 831 shared_informer.go:409] "Caches are synced"1545machine # [ 30.525801] k3s[831]: I1112 16:57:45.191498 831 shared_informer.go:409] "Caches are synced"1546machine # [ 30.527225] k3s[831]: I1112 16:57:45.191587 831 shared_informer.go:409] "Caches are synced"1547machine # [ 30.528625] k3s[831]: I1112 16:57:45.191798 831 shared_informer.go:409] "Caches are synced"1548machine # [ 30.529942] k3s[831]: I1112 16:57:45.191824 831 shared_informer.go:409] "Caches are synced"1549machine # [ 30.531262] k3s[831]: I1112 16:57:45.192387 831 shared_informer.go:409] "Caches are synced"1550machine # [ 30.533726] k3s[831]: I1112 16:57:45.192413 831 shared_informer.go:409] "Caches are synced"1551machine # [ 30.535149] k3s[831]: I1112 16:57:45.192531 831 shared_informer.go:409] "Caches are synced"1552machine # [ 30.536499] k3s[831]: I1112 16:57:45.192556 831 shared_informer.go:409] "Caches are synced"1553machine # [ 30.537847] k3s[831]: I1112 16:57:45.192584 831 shared_informer.go:409] "Caches are synced"1554machine # [ 30.539224] k3s[831]: I1112 16:57:45.193106 831 shared_informer.go:409] "Caches are synced"1555machine # [ 30.540892] k3s[831]: I1112 16:57:45.193153 831 range_allocator.go:177] "Sending events to api server"1556machine # [ 30.542340] k3s[831]: I1112 16:57:45.193184 831 range_allocator.go:181] "Starting range CIDR allocator"1557machine # [ 30.543888] k3s[831]: I1112 16:57:45.193191 831 shared_informer.go:402] "Waiting for caches to sync"1558machine # [ 30.545377] k3s[831]: I1112 16:57:45.193199 831 shared_informer.go:409] "Caches are synced"1559machine # [ 30.546672] k3s[831]: I1112 16:57:45.197491 831 shared_informer.go:409] "Caches are synced"1560machine # [ 30.548032] k3s[831]: I1112 16:57:45.197551 831 shared_informer.go:409] "Caches are synced"1561machine # [ 30.549393] k3s[831]: I1112 16:57:45.197590 831 shared_informer.go:409] "Caches are synced"1562machine # [ 30.550729] k3s[831]: I1112 16:57:45.197615 831 shared_informer.go:409] "Caches are synced"1563machine # [ 30.552196] k3s[831]: I1112 16:57:45.197641 831 shared_informer.go:409] "Caches are synced"1564machine # [ 30.553510] k3s[831]: I1112 16:57:45.197839 831 shared_informer.go:409] "Caches are synced"1565machine # [ 30.554812] k3s[831]: I1112 16:57:45.197880 831 shared_informer.go:409] "Caches are synced"1566machine # [ 30.556159] k3s[831]: I1112 16:57:45.197905 831 shared_informer.go:409] "Caches are synced"1567machine # [ 30.557483] k3s[831]: I1112 16:57:45.198465 831 shared_informer.go:409] "Caches are synced"1568machine # [ 30.558737] k3s[831]: I1112 16:57:45.198491 831 shared_informer.go:409] "Caches are synced"1569machine # [ 30.559975] k3s[831]: I1112 16:57:45.198559 831 node_lifecycle_controller.go:1217] "Initializing eviction metric for zone" zone=""1570machine # [ 30.561772] k3s[831]: I1112 16:57:45.198728 831 shared_informer.go:409] "Caches are synced"1571machine # [ 30.563046] k3s[831]: I1112 16:57:45.198778 831 shared_informer.go:409] "Caches are synced"1572machine # [ 30.564280] k3s[831]: I1112 16:57:45.198800 831 shared_informer.go:409] "Caches are synced"1573machine # [ 30.565571] k3s[831]: I1112 16:57:45.198831 831 shared_informer.go:409] "Caches are synced"1574machine # [ 30.566731] k3s[831]: I1112 16:57:45.198858 831 shared_informer.go:409] "Caches are synced"1575machine # [ 30.567883] k3s[831]: I1112 16:57:45.198886 831 shared_informer.go:409] "Caches are synced"1576machine # [ 30.569188] k3s[831]: I1112 16:57:45.198959 831 shared_informer.go:409] "Caches are synced"1577machine # [ 30.570509] k3s[831]: I1112 16:57:45.199102 831 shared_informer.go:409] "Caches are synced"1578machine # [ 30.571836] k3s[831]: I1112 16:57:45.199178 831 shared_informer.go:409] "Caches are synced"1579machine # [ 30.573119] k3s[831]: I1112 16:57:45.199206 831 shared_informer.go:409] "Caches are synced"1580machine # [ 30.574280] k3s[831]: I1112 16:57:45.199252 831 shared_informer.go:409] "Caches are synced"1581machine # [ 30.575475] k3s[831]: I1112 16:57:45.199274 831 shared_informer.go:409] "Caches are synced"1582machine # [ 30.577363] k3s[831]: I1112 16:57:45.199298 831 shared_informer.go:409] "Caches are synced"1583machine # [ 30.578953] k3s[831]: I1112 16:57:45.200559 831 node_lifecycle_controller.go:869] "Missing timestamp for Node. Assuming now as a timestamp" node="machine"1584machine # [ 30.580996] k3s[831]: I1112 16:57:45.200611 831 node_lifecycle_controller.go:1063] "Controller detected that zone is now in new state" zone="" newState="Normal"1585machine # [ 30.583036] k3s[831]: I1112 16:57:45.226049 831 shared_informer.go:409] "Caches are synced"1586machine # [ 30.584303] k3s[831]: I1112 16:57:45.247100 831 range_allocator.go:433] "Set node PodCIDR" node="machine" podCIDRs=["10.42.0.0/24"]1587machine # [ 30.585963] k3s[831]: time="2026-11-12T16:57:45Z" level=info msg="Flannel found PodCIDR assigned for node machine"1588machine # [ 30.587411] k3s[831]: time="2026-11-12T16:57:45Z" level=info msg="The interface eth0 with ipv4 address 10.0.2.15 will be used by flannel"1589machine # [ 30.589194] k3s[831]: I1112 16:57:45.268229 831 kube.go:139] Waiting 10m0s for node controller to sync1590machine # [ 30.590535] k3s[831]: I1112 16:57:45.268340 831 kube.go:537] Starting kube subnet manager1591machine # [ 30.591767] k3s[831]: I1112 16:57:45.289730 831 shared_informer.go:409] "Caches are synced"1592machine # [ 30.593079] k3s[831]: I1112 16:57:45.289795 831 shared_informer.go:409] "Caches are synced"1593machine # [ 30.594310] k3s[831]: I1112 16:57:45.289851 831 shared_informer.go:409] "Caches are synced"1594machine # [ 30.595612] k3s[831]: time="2026-11-12T16:57:45Z" level=info msg="Event occurred" apiVersion= fieldPath= kind=Node logger=k3s message="Deferred node password secret validation complete" object=machine reason=NodePasswordValidationComplete type=Normal1595machine # [ 30.598857] k3s[831]: time="2026-11-12T16:57:45Z" level=info msg="Adding node OwnerReference to node-password secret machine.node-password.k3s"1596machine # [ 31.016797] k3s[831]: time="2026-11-12T16:57:45Z" 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=Normal1597machine # [ 31.065987] k3s[831]: I1112 16:57:45.832869 831 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161598machine # [ 31.069114] k3s[831]: I1112 16:57:45.837141 831 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161599machine # [ 31.081921] systemd[1]: Created slice libcontainer container kubepods-burstable-podf2830427_0829_44fc_bbb3_6fa121171240.slice.1600machine # [ 31.135940] k3s[831]: I1112 16:57:45.905206 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"content\" (UniqueName: \"kubernetes.io/configmap/f2830427-0829-44fc-bbb3-6fa121171240-content\") pod \"helm-install-niks3-q2kb4\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") " pod="kube-system/helm-install-niks3-q2kb4"1601machine # [ 31.144291] k3s[831]: I1112 16:57:45.905264 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-648z2\" (UniqueName: \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-kube-api-access-648z2\") pod \"helm-install-niks3-q2kb4\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") " pod="kube-system/helm-install-niks3-q2kb4"1602machine # [ 31.152230] k3s[831]: I1112 16:57:45.905297 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-helm\") pod \"helm-install-niks3-q2kb4\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") " pod="kube-system/helm-install-niks3-q2kb4"1603machine # [ 31.159392] k3s[831]: I1112 16:57:45.905324 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-cache\") pod \"helm-install-niks3-q2kb4\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") " pod="kube-system/helm-install-niks3-q2kb4"1604machine # [ 31.168154] k3s[831]: I1112 16:57:45.905355 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-config\") pod \"helm-install-niks3-q2kb4\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") " pod="kube-system/helm-install-niks3-q2kb4"1605machine # [ 31.174213] k3s[831]: I1112 16:57:45.905378 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-tmp\") pod \"helm-install-niks3-q2kb4\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") " pod="kube-system/helm-install-niks3-q2kb4"1606machine # [ 31.184157] k3s[831]: I1112 16:57:45.905396 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"values\" (UniqueName: \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-values\") pod \"helm-install-niks3-q2kb4\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") " pod="kube-system/helm-install-niks3-q2kb4"1607machine # [ 31.202035] k3s[831]: I1112 16:57:45.971368 831 controller.go:667] quota admission added evaluator for: replicasets.apps1608machine # Error from server (NotFound): namespaces "niks3" not found1609machine # [ 31.498932] k3s[831]: I1112 16:57:46.268253 831 shared_informer.go:409] "Caches are synced"1610machine # [ 31.504128] k3s[831]: I1112 16:57:46.268651 831 kube.go:163] Node controller sync successful1611machine # [ 31.505444] k3s[831]: I1112 16:57:46.271344 831 vxlan.go:128] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false1612machine # [ 31.511959] k3s[831]: I1112 16:57:46.281293 831 shared_informer.go:409] "Caches are synced"1613machine # [ 31.515459] k3s[831]: I1112 16:57:46.284767 831 garbagecollector.go:166] "Garbage collector: all resource monitors have synced"1614machine # [ 31.517536] k3s[831]: I1112 16:57:46.284822 831 garbagecollector.go:169] "Proceeding to collect garbage"1615machine # [ 31.520166] k3s[831]: I1112 16:57:46.284336 831 kube.go:704] List of node(machine) annotations: map[string]string{"alpha.kubernetes.io/provided-node-ip":"10.0.2.15,fec0::530:692a:a8f:b554", "k3s.io/hostname":"machine", "k3s.io/internal-ip":"10.0.2.15,fec0::530:692a:a8f:b554", "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"}1616machine # [ 31.552190] k3s[831]: I1112 16:57:46.317706 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"config-volume\" (UniqueName: \"kubernetes.io/configmap/32d8b7b8-2cdf-48c5-b3ee-fa3c0b40718e-config-volume\") pod \"coredns-7cfb7bc9c7-8f4jh\" (UID: \"32d8b7b8-2cdf-48c5-b3ee-fa3c0b40718e\") " pod="kube-system/coredns-7cfb7bc9c7-8f4jh"1617machine # [ 31.556962] k3s[831]: I1112 16:57:46.317758 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-vb22c\" (UniqueName: \"kubernetes.io/projected/32d8b7b8-2cdf-48c5-b3ee-fa3c0b40718e-kube-api-access-vb22c\") pod \"coredns-7cfb7bc9c7-8f4jh\" (UID: \"32d8b7b8-2cdf-48c5-b3ee-fa3c0b40718e\") " pod="kube-system/coredns-7cfb7bc9c7-8f4jh"1618machine # [ 31.562582] k3s[831]: I1112 16:57:46.317790 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"custom-config-volume\" (UniqueName: \"kubernetes.io/configmap/32d8b7b8-2cdf-48c5-b3ee-fa3c0b40718e-custom-config-volume\") pod \"coredns-7cfb7bc9c7-8f4jh\" (UID: \"32d8b7b8-2cdf-48c5-b3ee-fa3c0b40718e\") " pod="kube-system/coredns-7cfb7bc9c7-8f4jh"1619machine # [ 31.575290] (udev-worker)[1170]: Network interface NamePolicy= disabled on kernel command line.1620machine # [ 31.586518] systemd[1]: Created slice libcontainer container kubepods-burstable-pod32d8b7b8_2cdf_48c5_b3ee_fa3c0b40718e.slice.1621machine # [ 31.618139] k3s[831]: I1112 16:57:46.387488 831 iptables.go:50] Starting flannel in iptables mode...1622machine # [ 31.619764] k3s[831]: time="2026-11-12T16:57:46Z" level=warning msg="no subnet found for key: FLANNEL_NETWORK in file: /run/flannel/subnet.env"1623machine # [ 31.622150] k3s[831]: time="2026-11-12T16:57:46Z" level=warning msg="no subnet found for key: FLANNEL_SUBNET in file: /run/flannel/subnet.env"1624machine # [ 31.624677] k3s[831]: time="2026-11-12T16:57:46Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_NETWORK in file: /run/flannel/subnet.env"1625machine # [ 31.627279] k3s[831]: time="2026-11-12T16:57:46Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_SUBNET in file: /run/flannel/subnet.env"1626machine # [ 31.630070] k3s[831]: I1112 16:57:46.389039 831 iptables.go:101] Current network or subnet (10.42.0.0/16, 10.42.0.0/24) is not equal to previous one (0.0.0.0/0, 0.0.0.0/0), trying to recycle old iptables rules1627machine # [ 31.632885] k3s[831]: I1112 16:57:46.390432 831 kube.go:558] Creating the node lease for IPv4. This is the n.Spec.PodCIDRs: [10.42.0.0/24]1628machine # [ 31.646720] k3s[831]: E1112 16:57:46.415962 831 remote_runtime.go:237] "RunPodSandbox from runtime service failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"5c8a8f0ac14437d512dfd751b4f7b500ee702660469b8ce3e1a4debc9006fd93\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory"1629machine # [ 31.653686] k3s[831]: E1112 16:57:46.421002 831 kuberuntime_sandbox.go:70] "Failed to create sandbox for pod" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"5c8a8f0ac14437d512dfd751b4f7b500ee702660469b8ce3e1a4debc9006fd93\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/helm-install-niks3-q2kb4"1630machine # [ 31.659156] k3s[831]: E1112 16:57:46.421080 831 kuberuntime_manager.go:1640] "CreatePodSandbox for pod failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"5c8a8f0ac14437d512dfd751b4f7b500ee702660469b8ce3e1a4debc9006fd93\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/helm-install-niks3-q2kb4"1631machine # [ 31.664449] k3s[831]: E1112 16:57:46.421203 831 pod_workers.go:1338] "Error syncing pod, skipping" err="failed to \"CreatePodSandbox\" for \"helm-install-niks3-q2kb4_kube-system(f2830427-0829-44fc-bbb3-6fa121171240)\" with CreatePodSandboxError: \"Failed to create sandbox for pod \\\"helm-install-niks3-q2kb4_kube-system(f2830427-0829-44fc-bbb3-6fa121171240)\\\": rpc error: code = Unknown desc = failed to setup network for sandbox \\\"5c8a8f0ac14437d512dfd751b4f7b500ee702660469b8ce3e1a4debc9006fd93\\\": plugin type=\\\"flannel\\\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory\"" pod="kube-system/helm-install-niks3-q2kb4" podUID="f2830427-0829-44fc-bbb3-6fa121171240"1632machine # [ 31.677830] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Started tunnel to 10.0.2.15:6443"1633machine # [ 31.679578] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Stopped tunnel to 127.0.0.1:6443"1634machine # [ 31.681685] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Connecting to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1635machine # [ 31.684147] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"1636machine # [ 31.686611] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"1637machine # [ 31.689742] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Handling backend connection request [machine]"1638machine # [ 31.691526] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1639machine # [ 31.693448] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Remotedialer connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1640machine # [ 31.696350] dhcpcd[583]: flannel.1: waiting for carrier1641machine # [ 31.697310] dhcpcd[583]: flannel.1: carrier acquired1642machine # [ 31.698120] dhcpcd[583]: flannel.1: IAID 24:80:01:971643machine # [ 31.698917] dhcpcd[583]: flannel.1: adding address fe80::4c35:24ff:fe80:1971644machine # [ 31.718254] k3s[831]: I1112 16:57:46.487583 831 iptables.go:111] Setting up masking rules1645machine # [ 31.729874] k3s[831]: I1112 16:57:46.499191 831 iptables.go:212] Changing default FORWARD chain policy to ACCEPT1646machine # [ 31.741988] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Wrote flannel subnet file to /run/flannel/subnet.env"1647machine # [ 31.743973] k3s[831]: time="2026-11-12T16:57:46Z" level=info msg="Running flannel backend"1648machine # [ 31.745673] k3s[831]: I1112 16:57:46.511323 831 vxlan_network.go:68] watching for new subnet leases1649machine # [ 31.747452] k3s[831]: I1112 16:57:46.514967 831 vxlan_network.go:115] starting vxlan device watcher1650machine # [ 31.785353] k3s[831]: I1112 16:57:46.554601 831 iptables.go:358] bootstrap done1651machine # [ 31.811156] k3s[831]: I1112 16:57:46.580475 831 iptables.go:358] bootstrap done1652machine # [ 31.962984] (udev-worker)[1212]: Network interface NamePolicy= disabled on kernel command line.1653machine # [ 31.985341] cni0: port 1(vethf641bc6c) entered blocking state1654machine # [ 31.985375] cni0: port 1(vethf641bc6c) entered disabled state1655machine # [ 31.985401] vethf641bc6c: entered allmulticast mode1656machine # [ 31.985847] vethf641bc6c: entered promiscuous mode1657machine # [ 32.007949] cni0: port 1(vethf641bc6c) entered blocking state1658machine # [ 32.007980] cni0: port 1(vethf641bc6c) entered forwarding state1659machine # [ 32.053114] dhcpcd[583]: vethf641bc6c: IAID 04:6c:fb:bb1660machine # [ 32.054104] dhcpcd[583]: vethf641bc6c: adding address fe80::7454:4ff:fe6c:fbbb1661machine # [ 32.144783] systemd[1]: Started libcontainer container 2f2d8421bd7399c5fa78ead301c7fa2d488467399be1c645deff5c300de5ac55.1662machine # [ 32.430240] dhcpcd[583]: vethf641bc6c: soliciting a DHCP lease1663machine # Error from server (NotFound): namespaces "niks3" not found1664machine # [ 32.923509] dhcpcd[583]: flannel.1: soliciting a DHCP lease1665machine # [ 33.084511] systemd[1]: Started libcontainer container a68e18a203e20cc0297762fc1d8b6817777097e69aa9c7db0a7fbf3b98ea5faa.1666machine # [ 33.190434] k3s[831]: I1112 16:57:47.959198 831 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/coredns-7cfb7bc9c7-8f4jh" podStartSLOduration=1.95917698 podStartE2EDuration="1.95917698s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 16:57:46 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 16:57:47.95463124 +0000 UTC m=+14.705359961" watchObservedRunningTime="2026-11-12 16:57:47.95917698 +0000 UTC m=+14.709905701"1667machine # Error from server (NotFound): namespaces "niks3" not found1668machine # [ 34.302629] dhcpcd[583]: vethf641bc6c: soliciting an IPv6 router1669machine # [ 34.427514] dhcpcd[583]: flannel.1: soliciting an IPv6 router1670machine # Error from server (NotFound): namespaces "niks3" not found1671machine # Error from server (NotFound): namespaces "niks3" not found1672machine # [ 37.431405] dhcpcd[583]: vethf641bc6c: probing for an IPv4LL address1673machine # Error from server (NotFound): namespaces "niks3" not found1674machine # [ 37.620928] k3s[831]: I1112 16:57:52.389526 831 kuberuntime_manager.go:2172] "Updating runtime config through cri with podcidr" CIDR="10.42.0.0/24"1675machine # [ 37.623126] k3s[831]: I1112 16:57:52.390886 831 kubelet_network.go:48] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="10.42.0.0/24"1676machine # [ 37.924218] dhcpcd[583]: flannel.1: probing for an IPv4LL address1677machine # [ 38.640323] k3s[831]: time="2026-11-12T16:57:53Z" level=info msg="Starting network policy controller version v2.6.3-k3s1, built on 1970-01-01T01:01:01Z, go1.26.10"1678machine # [ 38.643723] k3s[831]: I1112 16:57:53.408774 831 network_policy_controller.go:164] Starting network policy controller1679machine # [ 38.838007] k3s[831]: I1112 16:57:53.607319 831 network_policy_controller.go:179] Starting network policy controller full sync goroutine1680machine # Error from server (NotFound): namespaces "niks3" not found1681machine # Error from server (NotFound): namespaces "niks3" not found1682machine # Error from server (NotFound): namespaces "niks3" not found1683machine # Error from server (NotFound): namespaces "niks3" not found1684machine # [ 42.565511] dhcpcd[583]: vethf641bc6c: using IPv4LL address 169.254.29.1971685machine # [ 42.566660] dhcpcd[583]: vethf641bc6c: adding route to 169.254.0.0/161686machine # [ 43.504509] dhcpcd[583]: flannel.1: using IPv4LL address 169.254.89.141687machine # [ 43.504900] dhcpcd[583]: flannel.1: adding route to 169.254.0.0/161688machine # [ 43.561163] (udev-worker)[1608]: Network interface NamePolicy= disabled on kernel command line.1689machine # [ 43.573274] cni0: port 2(veth82f870e4) entered blocking state1690machine # [ 43.573310] cni0: port 2(veth82f870e4) entered disabled state1691machine # [ 43.573343] veth82f870e4: entered allmulticast mode1692machine # [ 43.573477] veth82f870e4: entered promiscuous mode1693machine # [ 43.613316] cni0: port 2(veth82f870e4) entered blocking state1694machine # [ 43.613354] cni0: port 2(veth82f870e4) entered forwarding state1695machine # [ 43.671260] dhcpcd[583]: veth82f870e4: waiting for carrier1696machine # [ 43.672905] dhcpcd[583]: veth82f870e4: carrier acquired1697machine # [ 43.676399] dhcpcd[583]: veth82f870e4: IAID 74:7d:7a:901698machine # [ 43.678702] dhcpcd[583]: veth82f870e4: adding address fe80::f4ae:74ff:fe7d:7a901699machine # [ 43.752926] systemd[1]: Started libcontainer container 38a4e728c133c0e1a8682e816a7ef7dc4f07fb1c67c417f882af063fef2ace98.1700machine # Error from server (NotFound): namespaces "niks3" not found1701machine # [ 44.062090] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount3172300844.mount: Deactivated successfully.1702machine # [ 45.026004] dhcpcd[583]: veth82f870e4: soliciting a DHCP lease1703machine # Error from server (NotFound): namespaces "niks3" not found1704machine # [ 45.361275] systemd[1]: Started libcontainer container 8f29fef9e774237c76c57d87676c21a7eb8617515b6b9402dc52f6fda71aed9c.1705machine # [ 45.411965] dhcpcd[583]: veth82f870e4: soliciting an IPv6 router1706machine # [ 45.495890] k3s[831]: I1112 16:58:00.264586 831 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/helm-install-niks3-q2kb4" podStartSLOduration=15.26456072 podStartE2EDuration="15.26456072s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 16:57:45 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 16:58:00.26444916 +0000 UTC m=+27.015177881" watchObservedRunningTime="2026-11-12 16:58:00.26456072 +0000 UTC m=+27.015289441"1707machine # [ 46.306140] dhcpcd[583]: vethf641bc6c: no IPv6 Routers available1708machine # [ 46.392044] k3s[831]: I1112 16:58:01.161316 831 alloc.go:329] "allocated clusterIPs" service="niks3/niks3" clusterIPs={"IPv4":"10.43.238.16"}1709machine # [ 46.429699] dhcpcd[583]: flannel.1: no IPv6 Routers available1710machine # [ 46.458306] k3s[831]: I1112 16:58:01.227537 831 controller.go:667] quota admission added evaluator for: cronjobs.batch1711machine # Error from server (NotFound): deployments.apps "niks3" not found1712machine # [ 46.505951] systemd[1]: cri-containerd-8f29fef9e774237c76c57d87676c21a7eb8617515b6b9402dc52f6fda71aed9c.scope: Deactivated successfully.1713machine # [ 46.510172] systemd[1]: cri-containerd-8f29fef9e774237c76c57d87676c21a7eb8617515b6b9402dc52f6fda71aed9c.scope: Consumed 885ms CPU time over 1.147s wall clock time, 36.9M memory peak, 4.5M incoming IP traffic, 96.9K outgoing IP traffic.1714machine # [ 46.536718] k3s[831]: E1112 16:58:01.305206 831 replica_set.go:640] "Unhandled Error" err="sync \"niks3/niks3-688c9f4967\" failed with read version: 443 is not as new as written version: 449 for group resource replicasets.apps" logger="UnhandledError"1715machine # [ 46.580910] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-8f29fef9e774237c76c57d87676c21a7eb8617515b6b9402dc52f6fda71aed9c-rootfs.mount: Deactivated successfully.1716machine # [ 46.592954] k3s[831]: I1112 16:58:01.357309 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"db\" (UniqueName: \"kubernetes.io/secret/b6c114d2-dd12-4c48-85a3-9ea42a0714a4-db\") pod \"niks3-688c9f4967-6mwtp\" (UID: \"b6c114d2-dd12-4c48-85a3-9ea42a0714a4\") " pod="niks3/niks3-688c9f4967-6mwtp"1717machine # [ 46.614304] k3s[831]: I1112 16:58:01.357349 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"oidc\" (UniqueName: \"kubernetes.io/configmap/b6c114d2-dd12-4c48-85a3-9ea42a0714a4-oidc\") pod \"niks3-688c9f4967-6mwtp\" (UID: \"b6c114d2-dd12-4c48-85a3-9ea42a0714a4\") " pod="niks3/niks3-688c9f4967-6mwtp"1718machine # [ 46.623172] k3s[831]: I1112 16:58:01.357416 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"s3\" (UniqueName: \"kubernetes.io/secret/b6c114d2-dd12-4c48-85a3-9ea42a0714a4-s3\") pod \"niks3-688c9f4967-6mwtp\" (UID: \"b6c114d2-dd12-4c48-85a3-9ea42a0714a4\") " pod="niks3/niks3-688c9f4967-6mwtp"1719machine # [ 46.628255] k3s[831]: I1112 16:58:01.357468 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/b6c114d2-dd12-4c48-85a3-9ea42a0714a4-token\") pod \"niks3-688c9f4967-6mwtp\" (UID: \"b6c114d2-dd12-4c48-85a3-9ea42a0714a4\") " pod="niks3/niks3-688c9f4967-6mwtp"1720machine # [ 46.636550] k3s[831]: I1112 16:58:01.357486 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-cvz8q\" (UniqueName: \"kubernetes.io/projected/b6c114d2-dd12-4c48-85a3-9ea42a0714a4-kube-api-access-cvz8q\") pod \"niks3-688c9f4967-6mwtp\" (UID: \"b6c114d2-dd12-4c48-85a3-9ea42a0714a4\") " pod="niks3/niks3-688c9f4967-6mwtp"1721machine # [ 46.642897] systemd[1]: Created slice libcontainer container kubepods-besteffort-podb6c114d2_dd12_4c48_85a3_9ea42a0714a4.slice.1722machine # [ 47.151629] cni0: port 3(vethbe5170e8) entered blocking state1723machine # [ 47.151680] cni0: port 3(vethbe5170e8) entered disabled state1724machine # [ 47.151720] vethbe5170e8: entered allmulticast mode1725machine # [ 47.151883] vethbe5170e8: entered promiscuous mode1726machine # [ 47.178724] cni0: port 3(vethbe5170e8) entered blocking state1727machine # [ 47.178763] cni0: port 3(vethbe5170e8) entered forwarding state1728machine # [ 47.239892] (udev-worker)[1974]: Network interface NamePolicy= disabled on kernel command line.1729machine # [ 47.276204] dhcpcd[583]: vethbe5170e8: IAID 6a:88:12:921730machine # [ 47.277301] dhcpcd[583]: vethbe5170e8: adding address fe80::ecd6:6aff:fe88:12921731machine # [ 47.400618] systemd[1]: Started libcontainer container d6a4ef531389319ecd32b432672b62333e5e5000857657c7e697e406df5d9f93.1732machine # [ 47.423335] dhcpcd[583]: vethbe5170e8: soliciting a DHCP lease1733machine # [ 48.005036] systemd[1]: Started libcontainer container 7d969d2259021bedc7a2d65175f4aafa40a01003b3c47649742266cbdb42d073.1734machine # [ 48.120773] k3s[831]: I1112 16:58:02.889544 831 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-688c9f4967-6mwtp" podStartSLOduration=1.8895038199999998 podStartE2EDuration="1.88950382s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 16:58:01 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 16:58:02.88291878 +0000 UTC m=+29.633647501" watchObservedRunningTime="2026-11-12 16:58:02.88950382 +0000 UTC m=+29.640232541"1735machine # [ 48.756280] systemd[1]: cri-containerd-38a4e728c133c0e1a8682e816a7ef7dc4f07fb1c67c417f882af063fef2ace98.scope: Deactivated successfully.1736machine # [ 48.818584] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-38a4e728c133c0e1a8682e816a7ef7dc4f07fb1c67c417f882af063fef2ace98-rootfs.mount: Deactivated successfully.1737machine # [ 48.937111] dhcpcd[583]: vethbe5170e8: soliciting an IPv6 router1738machine # [ 49.073816] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-38a4e728c133c0e1a8682e816a7ef7dc4f07fb1c67c417f882af063fef2ace98-shm.mount: Deactivated successfully.1739machine # [ 49.138133] dhcpcd[583]: veth82f870e4: carrier lost1740machine # [ 49.145421] cni0: port 2(veth82f870e4) entered disabled state1741machine # [ 49.149309] veth82f870e4 (unregistering): left allmulticast mode1742machine # [ 49.149340] veth82f870e4 (unregistering): left promiscuous mode1743machine # [ 49.149356] cni0: port 2(veth82f870e4) entered disabled state1744machine # [ 49.185632] dhcpcd[583]: veth82f870e4: deleting address fe80::f4ae:74ff:fe7d:7a901745machine # [ 49.205771] systemd[1]: run-netns-cni\x2dd4c8d145\x2dcb8f\x2d1ef9\x2d8455\x2d36711399d4ae.mount: Deactivated successfully.1746machine # [ 49.240368] dhcpcd[583]: veth82f870e4: removing interface1747machine # [ 49.310215] k3s[831]: I1112 16:58:04.078193 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-cache\") pod \"f2830427-0829-44fc-bbb3-6fa121171240\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") "1748machine # [ 49.317626] k3s[831]: I1112 16:58:04.078244 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-tmp\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-tmp\") pod \"f2830427-0829-44fc-bbb3-6fa121171240\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") "1749machine # [ 49.322591] k3s[831]: I1112 16:58:04.078281 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-kube-api-access-648z2\" (UniqueName: \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-kube-api-access-648z2\") pod \"f2830427-0829-44fc-bbb3-6fa121171240\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") "1750machine # [ 49.328528] k3s[831]: I1112 16:58:04.078302 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-helm\") pod \"f2830427-0829-44fc-bbb3-6fa121171240\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") "1751machine # [ 49.336296] k3s[831]: I1112 16:58:04.078322 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-config\") pod \"f2830427-0829-44fc-bbb3-6fa121171240\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") "1752machine # [ 49.341300] k3s[831]: I1112 16:58:04.078344 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-values\" (UniqueName: \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-values\") pod \"f2830427-0829-44fc-bbb3-6fa121171240\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") "1753machine # [ 49.347690] k3s[831]: I1112 16:58:04.078370 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/configmap/f2830427-0829-44fc-bbb3-6fa121171240-content\" (UniqueName: \"kubernetes.io/configmap/f2830427-0829-44fc-bbb3-6fa121171240-content\") pod \"f2830427-0829-44fc-bbb3-6fa121171240\" (UID: \"f2830427-0829-44fc-bbb3-6fa121171240\") "1754machine # [ 49.352507] k3s[831]: I1112 16:58:04.078843 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/configmap/f2830427-0829-44fc-bbb3-6fa121171240-content" pod "f2830427-0829-44fc-bbb3-6fa121171240" (UID: "f2830427-0829-44fc-bbb3-6fa121171240"). InnerVolumeSpecName "content". PluginName "kubernetes.io/configmap", VolumeGIDValue ""1755machine # [ 49.357078] k3s[831]: I1112 16:58:04.104399 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-cache" pod "f2830427-0829-44fc-bbb3-6fa121171240" (UID: "f2830427-0829-44fc-bbb3-6fa121171240"). InnerVolumeSpecName "klipper-cache". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1756machine # [ 49.362988] systemd[1]: var-lib-kubelet-pods-f2830427\x2d0829\x2d44fc\x2dbbb3\x2d6fa121171240-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dcache.mount: Deactivated successfully.1757machine # [ 49.365374] systemd[1]: var-lib-kubelet-pods-f2830427\x2d0829\x2d44fc\x2dbbb3\x2d6fa121171240-volumes-kubernetes.io\x7eempty\x2ddir-tmp.mount: Deactivated successfully.1758machine # [ 49.367639] k3s[831]: I1112 16:58:04.135215 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-tmp" pod "f2830427-0829-44fc-bbb3-6fa121171240" (UID: "f2830427-0829-44fc-bbb3-6fa121171240"). InnerVolumeSpecName "tmp". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1759machine # [ 49.374209] k3s[831]: I1112 16:58:04.143374 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-values" pod "f2830427-0829-44fc-bbb3-6fa121171240" (UID: "f2830427-0829-44fc-bbb3-6fa121171240"). InnerVolumeSpecName "values". PluginName "kubernetes.io/projected", VolumeGIDValue ""1760machine # [ 49.379149] k3s[831]: I1112 16:58:04.148488 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-kube-api-access-648z2" pod "f2830427-0829-44fc-bbb3-6fa121171240" (UID: "f2830427-0829-44fc-bbb3-6fa121171240"). InnerVolumeSpecName "kube-api-access-648z2". PluginName "kubernetes.io/projected", VolumeGIDValue ""1761machine # [ 49.384081] k3s[831]: I1112 16:58:04.148692 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-helm" pod "f2830427-0829-44fc-bbb3-6fa121171240" (UID: "f2830427-0829-44fc-bbb3-6fa121171240"). InnerVolumeSpecName "klipper-helm". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1762machine # [ 49.388828] k3s[831]: I1112 16:58:04.158165 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-config" pod "f2830427-0829-44fc-bbb3-6fa121171240" (UID: "f2830427-0829-44fc-bbb3-6fa121171240"). InnerVolumeSpecName "klipper-config". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1763machine # [ 49.409808] k3s[831]: I1112 16:58:04.178986 831 reconciler_common.go:299] "Volume detached for volume \"kube-api-access-648z2\" (UniqueName: \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-kube-api-access-648z2\") on node \"machine\" DevicePath \"\""1764machine # [ 49.413262] k3s[831]: I1112 16:58:04.179038 831 reconciler_common.go:299] "Volume detached for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-helm\") on node \"machine\" DevicePath \"\""1765machine # [ 49.416543] k3s[831]: I1112 16:58:04.179054 831 reconciler_common.go:299] "Volume detached for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-config\") on node \"machine\" DevicePath \"\""1766machine # [ 49.419523] k3s[831]: I1112 16:58:04.179077 831 reconciler_common.go:299] "Volume detached for volume \"values\" (UniqueName: \"kubernetes.io/projected/f2830427-0829-44fc-bbb3-6fa121171240-values\") on node \"machine\" DevicePath \"\""1767machine # [ 49.422528] k3s[831]: I1112 16:58:04.179088 831 reconciler_common.go:299] "Volume detached for volume \"content\" (UniqueName: \"kubernetes.io/configmap/f2830427-0829-44fc-bbb3-6fa121171240-content\") on node \"machine\" DevicePath \"\""1768machine # [ 49.425491] k3s[831]: I1112 16:58:04.179098 831 reconciler_common.go:299] "Volume detached for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-klipper-cache\") on node \"machine\" DevicePath \"\""1769machine # [ 49.428506] k3s[831]: I1112 16:58:04.179110 831 reconciler_common.go:299] "Volume detached for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/f2830427-0829-44fc-bbb3-6fa121171240-tmp\") on node \"machine\" DevicePath \"\""1770machine # [ 49.518213] systemd[1]: Removed slice libcontainer container kubepods-burstable-podf2830427_0829_44fc_bbb3_6fa121171240.slice.1771machine # [ 49.520771] systemd[1]: kubepods-burstable-podf2830427_0829_44fc_bbb3_6fa121171240.slice: Consumed 920ms CPU time over 18.436s wall clock time, 37.4M memory peak, 4.5M incoming IP traffic, 97K outgoing IP traffic.1772machine # [ 49.742168] k3s[831]: I1112 16:58:04.511209 831 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="38a4e728c133c0e1a8682e816a7ef7dc4f07fb1c67c417f882af063fef2ace98"1773machine # [ 49.747405] k3s[831]: E1112 16:58:04.511387 831 kubelet_pods.go:2193] "failed to read memory cgroup config for the pod" err="failed to read memory.max for cgroup /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podf2830427_0829_44fc_bbb3_6fa121171240.slice: openat2 /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podf2830427_0829_44fc_bbb3_6fa121171240.slice/memory.max: no such file or directory" podName="helm-install-niks3-q2kb4"1774machine # [ 49.756758] k3s[831]: E1112 16:58:04.511486 831 kubelet_pods.go:2198] "failed to read memory cgroup limits for the pod" err="failed to read cpu.max file for cgroup /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podf2830427_0829_44fc_bbb3_6fa121171240.slice: openat2 /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-podf2830427_0829_44fc_bbb3_6fa121171240.slice/cpu.max: no such file or directory" podName="helm-install-niks3-q2kb4"1775machine # [ 49.812978] systemd[1]: var-lib-kubelet-pods-f2830427\x2d0829\x2d44fc\x2dbbb3\x2d6fa121171240-volumes-kubernetes.io\x7eprojected-kube\x2dapi\x2daccess\x2d648z2.mount: Deactivated successfully.1776machine # [ 49.818836] systemd[1]: var-lib-kubelet-pods-f2830427\x2d0829\x2d44fc\x2dbbb3\x2d6fa121171240-volumes-kubernetes.io\x7eprojected-values.mount: Deactivated successfully.1777machine # [ 49.822779] systemd[1]: var-lib-kubelet-pods-f2830427\x2d0829\x2d44fc\x2dbbb3\x2d6fa121171240-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dconfig.mount: Deactivated successfully.1778machine # [ 49.828810] systemd[1]: var-lib-kubelet-pods-f2830427\x2d0829\x2d44fc\x2dbbb3\x2d6fa121171240-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dhelm.mount: Deactivated successfully.1779machine # [ 52.424805] dhcpcd[583]: vethbe5170e8: probing for an IPv4LL address1780[53.59s] machine: (finished: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s, in 27.18 seconds)1781[53.59s] machine: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true1782[53.81s] machine: (finished: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true, in 0.22 seconds)1783[53.81s] machine: waiting for success: curl -sf http://localhost:30051/readyz | grep OK1784[53.86s] machine: (finished: waiting for success: curl -sf http://localhost:30051/readyz | grep OK, in 0.05 seconds)1785[53.86s] (finished: subtest: chart deploys and becomes ready, in 27.45 seconds)1786[53.86s] machine: waiting for success: kubectl -n ci get sa builder1787[54.04s] machine: (finished: waiting for success: kubectl -n ci get sa builder, in 0.19 seconds)1788[54.04s] machine: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt1789[54.24s] machine: (finished: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt, in 0.19 seconds)1790[54.24s] machine: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt1791[54.43s] machine: (finished: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt, in 0.19 seconds)1792[54.43s] machine: must succeed: readlink -f /run/current-system/sw/bin/niks31793[54.44s] machine: (finished: must succeed: readlink -f /run/current-system/sw/bin/niks3, in 0.02 seconds)1794[54.44s] subtest: allowed service account can push via workload identity1795[54.44s] 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>&11796[55.52s] 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.08 seconds)1797[55.52s] machine: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/an044afijna5agsc71nj88va0jbxiq27.narinfo1798[55.55s] 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)1799[55.55s] (finished: subtest: allowed service account can push via workload identity, in 1.10 seconds)1800[55.55s] subtest: write scope does not grant admin1801[55.55s] machine: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status1802[55.58s] 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)1803[55.58s] (finished: subtest: write scope does not grant admin, in 0.03 seconds)1804[55.58s] subtest: other service accounts are rejected1805[55.58s] 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>&11806[55.72s] 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.14 seconds)1807[55.72s] (finished: subtest: other service accounts are rejected, in 0.14 seconds)1808[55.72s] subtest: gc cronjob runs against the service1809[55.72s] machine: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual1810[55.89s] machine: (finished: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual, in 0.17 seconds)1811[55.89s] machine: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s1812machine # [ 55.173664] systemd[1]: Created slice libcontainer container kubepods-besteffort-poda550e748_b745_4eba_be5d_96ad90ff3434.slice.1813machine # [ 55.259850] k3s[831]: I1112 16:58:10.028517 831 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/a550e748-b745-4eba-be5d-96ad90ff3434-token\") pod \"gc-manual-thk8s\" (UID: \"a550e748-b745-4eba-be5d-96ad90ff3434\") " pod="niks3/gc-manual-thk8s"1814machine # [ 55.551757] cni0: port 2(vethb65f0d0e) entered blocking state1815machine # [ 55.551796] cni0: port 2(vethb65f0d0e) entered disabled state1816machine # [ 55.551851] vethb65f0d0e: entered allmulticast mode1817machine # [ 55.552003] vethb65f0d0e: entered promiscuous mode1818machine # [ 55.592317] cni0: port 2(vethb65f0d0e) entered blocking state1819machine # [ 55.592354] cni0: port 2(vethb65f0d0e) entered forwarding state1820machine # [ 55.632591] (udev-worker)[2472]: Network interface NamePolicy= disabled on kernel command line.1821machine # [ 55.674085] dhcpcd[583]: vethb65f0d0e: IAID a1:71:97:e21822machine # [ 55.675137] dhcpcd[583]: vethb65f0d0e: adding address fe80::f4db:a1ff:fe71:97e21823machine # [ 55.716411] systemd[1]: Started libcontainer container 94ebfc5161318f6c9f3779dfd12be200748b561d60d64a8afcf5e21a2e694d69.1824machine # [ 55.868703] systemd[1]: Started libcontainer container cff661b73997d9e0172edb07965f09afbed82b0db22f63ef1298b6fdac64e7ef.1825machine # [ 56.503949] dhcpcd[583]: vethb65f0d0e: soliciting a DHCP lease1826machine # [ 56.959378] dhcpcd[583]: vethbe5170e8: using IPv4LL address 169.254.58.2351827machine # [ 56.961421] dhcpcd[583]: vethbe5170e8: adding route to 169.254.0.0/161828machine # [ 57.417953] dhcpcd[583]: vethb65f0d0e: soliciting an IPv6 router1829machine # [ 57.948266] systemd[1]: cri-containerd-cff661b73997d9e0172edb07965f09afbed82b0db22f63ef1298b6fdac64e7ef.scope: Deactivated successfully.1830machine # [ 57.951510] systemd[1]: cri-containerd-cff661b73997d9e0172edb07965f09afbed82b0db22f63ef1298b6fdac64e7ef.scope: Consumed 41ms CPU time over 2.079s wall clock time, 15.6M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1831machine # [ 58.013143] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-cff661b73997d9e0172edb07965f09afbed82b0db22f63ef1298b6fdac64e7ef-rootfs.mount: Deactivated successfully.1832machine # [ 59.802042] systemd[1]: cri-containerd-94ebfc5161318f6c9f3779dfd12be200748b561d60d64a8afcf5e21a2e694d69.scope: Deactivated successfully.1833machine # [ 59.867356] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-94ebfc5161318f6c9f3779dfd12be200748b561d60d64a8afcf5e21a2e694d69-rootfs.mount: Deactivated successfully.1834machine # [ 59.912949] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-94ebfc5161318f6c9f3779dfd12be200748b561d60d64a8afcf5e21a2e694d69-shm.mount: Deactivated successfully.1835machine # [ 59.963118] dhcpcd[583]: vethb65f0d0e: carrier lost[ 59.970223] cni0: port 2(vethb65f0d0e) entered disabled state1836machine # 1837machine # [ 59.973210] vethb65f0d0e (unregistering): left allmulticast mode1838machine # [ 59.973238] vethb65f0d0e (unregistering): left promiscuous mode1839machine # [ 59.973253] cni0: port 2(vethb65f0d0e) entered disabled state1840machine # [ 60.010367] systemd[1]: run-netns-cni\x2d12f87eac\x2d0e67\x2d5307\x2dd708\x2da5ed7aec99ab.mount: Deactivated successfully.1841machine # [ 60.019936] dhcpcd[583]: vethb65f0d0e: deleting address fe80::f4db:a1ff:fe71:97e21842machine # [ 60.080124] dhcpcd[583]: vethb65f0d0e: removing interface1843machine # [ 60.193227] k3s[831]: I1112 16:58:14.961598 831 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/secret/a550e748-b745-4eba-be5d-96ad90ff3434-token\" (UniqueName: \"kubernetes.io/secret/a550e748-b745-4eba-be5d-96ad90ff3434-token\") pod \"a550e748-b745-4eba-be5d-96ad90ff3434\" (UID: \"a550e748-b745-4eba-be5d-96ad90ff3434\") "1844machine # [ 60.203187] systemd[1]: var-lib-kubelet-pods-a550e748\x2db745\x2d4eba\x2dbe5d\x2d96ad90ff3434-volumes-kubernetes.io\x7esecret-token.mount: Deactivated successfully.1845machine # [ 60.206381] k3s[831]: I1112 16:58:14.975626 831 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/a550e748-b745-4eba-be5d-96ad90ff3434-token" pod "a550e748-b745-4eba-be5d-96ad90ff3434" (UID: "a550e748-b745-4eba-be5d-96ad90ff3434"). InnerVolumeSpecName "token". PluginName "kubernetes.io/secret", VolumeGIDValue ""1846machine # [ 60.293478] k3s[831]: I1112 16:58:15.062729 831 reconciler_common.go:299] "Volume detached for volume \"token\" (UniqueName: \"kubernetes.io/secret/a550e748-b745-4eba-be5d-96ad90ff3434-token\") on node \"machine\" DevicePath \"\""1847machine # [ 60.686076] systemd-coredump[2730]: Process 583 (dhcpcd) of user 999 terminated abnormally with signal 11/SEGV, processing...1848machine # [ 60.694301] systemd[1]: Created slice Slice /system/systemd-coredump.1849machine # [ 60.699533] systemd[1]: Started Process Core Dump (PID 2730/UID 0).1850machine # [ 60.785499] k3s[831]: I1112 16:58:15.554171 831 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="94ebfc5161318f6c9f3779dfd12be200748b561d60d64a8afcf5e21a2e694d69"1851machine # [ 60.798221] systemd[1]: Removed slice libcontainer container kubepods-besteffort-poda550e748_b745_4eba_be5d_96ad90ff3434.slice.1852machine # [ 60.806689] systemd[1]: kubepods-besteffort-poda550e748_b745_4eba_be5d_96ad90ff3434.slice: Consumed 81ms CPU time over 5.624s wall clock time, 16.2M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1853[61.62s] machine: (finished: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s, in 5.73 seconds)1854[61.62s] (finished: subtest: gc cronjob runs against the service, in 5.90 seconds)1855[61.62s] subtest: helm test hook passes1856[61.62s] machine: must succeed: helm test -n niks3 niks3 --timeout 2m >&21857machine # [ 60.877849] systemd-coredump[2731]: Process 583 (dhcpcd) of user 999 dumped core.1858machine # 1859machine # Module udev.so without build-id.1860machine # Module dhcpcd without build-id.1861machine # Stack trace of thread 583:1862machine # #0 0x0000add7c35f5c94 ipv6nd_expire (dhcpcd + 0x35c94)1863machine # #1 0x0000add7c35d1b90 eloop_start (dhcpcd + 0x11b90)1864machine # #2 0x0000add7c35c9fc0 main (dhcpcd + 0x9fc0)1865machine # #3 0x0000f185eb2b6f74 __libc_start_call_main (libc.so.6 + 0x26f74)1866machine # #4 0x0000f185eb2b70b8 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x270b8)1867machine # #5 0x0000add7c35cafb0 _start (dhcpcd + 0xafb0)1868machine # ELF object binary architecture: AARCH641869machine # 1870machine # [ 60.895161] systemd[1]: systemd-coredump@0-1-2730_2731-0.service: Deactivated successfully.1871machine # [ 60.981742] systemd[1]: dhcpcd.service: Main process exited, code=dumped, status=11/SEGV1872machine # [ 60.983659] systemd[1]: dhcpcd.service: Failed with result 'core-dump'.1873machine # [ 60.986866] systemd[1]: dhcpcd.service: Consumed 521ms CPU time over 53.304s wall clock time, 9M memory peak, 8K written to disk, 96B incoming IP traffic, 784B outgoing IP traffic.1874machine # [ 61.316253] systemd[1]: dhcpcd.service: Scheduled restart job, restart counter is at 1.1875machine # [ 61.327038] systemd[1]: Starting DHCP Client...1876machine # [ 61.473523] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod169b4551_c90d_4e27_acbe_7c533e9b5776.slice.1877machine # [ 61.500941] dhcpcd[2753]: dhcpcd-10.3.2 starting1878machine # [ 61.507078] dhcpcd[2760]: dev: loaded udev1879machine # [ 61.507937] dhcpcd[2760]: DUID 00:01:00:01:32:88:ac:72:52:54:00:12:34:561880machine # [ 61.577937] dhcpcd[2760]: eth0: IAID 00:12:34:561881machine # [ 61.580238] dhcpcd[2760]: flannel.1: IAID 24:80:01:971882machine # [ 61.581064] dhcpcd[2760]: vethf641bc6c: IAID 04:6c:fb:bb1883machine # [ 61.581846] dhcpcd[2760]: vethbe5170e8: IAID 6a:88:12:921884machine # [ 61.600371] (udev-worker)[2696]: Network interface NamePolicy= disabled on kernel command line.1885machine # [ 61.609072] cni0: port 2(veth58cba056) entered blocking state1886machine # [ 61.609104] cni0: port 2(veth58cba056) entered disabled state1887machine # [ 61.609131] veth58cba056: entered allmulticast mode1888machine # [ 61.609233] veth58cba056: entered promiscuous mode1889machine # [ 61.629706] cni0: port 2(veth58cba056) entered blocking state1890machine # [ 61.629739] cni0: port 2(veth58cba056) entered forwarding state1891machine # [ 61.661278] dhcpcd[2760]: veth58cba056: IAID 3f:b7:b3:061892machine # [ 61.663199] dhcpcd[2760]: veth58cba056: adding address fe80::80e5:3fff:feb7:b3061893machine # [ 61.845204] systemd[1]: Started libcontainer container 9faeca16da53fb1c89133f564488f85609a1bd171e5171740f0c946ff33fda61.1894machine # [ 62.100794] systemd[1]: Started libcontainer container 9a44bd0b9e55db2165542381cefde6615b38ab5b64de0bc25dde3b82091cc9cf.1895machine # [ 62.158747] dhcpcd[2760]: flannel.1: soliciting an IPv6 router1896machine # [ 62.197859] systemd[1]: cri-containerd-9a44bd0b9e55db2165542381cefde6615b38ab5b64de0bc25dde3b82091cc9cf.scope: Deactivated successfully.1897machine # [ 62.203707] systemd[1]: cri-containerd-9a44bd0b9e55db2165542381cefde6615b38ab5b64de0bc25dde3b82091cc9cf.scope: Consumed 45ms CPU time over 96ms wall clock time, 14.1M memory peak, 693B incoming IP traffic, 495B outgoing IP traffic.1898machine # [ 62.221850] dhcpcd[2760]: eth0: soliciting an IPv6 router1899machine # [ 62.224324] dhcpcd[2760]: eth0: Router Advertisement from fe80::21900machine # [ 62.225397] dhcpcd[2760]: eth0: adding address fec0::5054:ff:fe12:3456/641901machine # [ 62.263972] k3s[831]: I1112 16:58:17.032418 831 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-test" podStartSLOduration=1.03237848 podStartE2EDuration="1.03237848s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-11-12 16:58:16 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-11-12 16:58:17.02726788 +0000 UTC m=+43.777996601" watchObservedRunningTime="2026-11-12 16:58:17.03237848 +0000 UTC m=+43.783107201"1902machine # [ 62.299183] dhcpcd[2760]: veth58cba056: soliciting a DHCP lease1903machine # [ 62.309745] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-9a44bd0b9e55db2165542381cefde6615b38ab5b64de0bc25dde3b82091cc9cf-rootfs.mount: Deactivated successfully.1904machine # [ 62.425206] dhcpcd[2760]: vethbe5170e8: soliciting an IPv6 router1905machine # [ 62.445336] dhcpcd[2760]: vethf641bc6c: soliciting an IPv6 router1906machine # [ 62.784423] dhcpcd[2760]: eth0: rebinding lease of 10.0.2.151907machine # [ 62.811319] dhcpcd[2760]: eth0: leased 10.0.2.15 for 86400 seconds1908machine # [ 62.869703] systemd[1]: Started DHCP Client.1909machine # [ 62.987951] dhcpcd[2760]: vethf641bc6c: soliciting a DHCP lease1910machine # [ 63.128808] dhcpcd[2760]: veth58cba056: soliciting an IPv6 router1911machine # [ 63.142216] dhcpcd[2760]: flannel.1: soliciting a DHCP lease1912machine # [ 63.192144] dhcpcd[2760]: vethbe5170e8: soliciting a DHCP lease1913machine # [ 63.820818] systemd[1]: cri-containerd-9faeca16da53fb1c89133f564488f85609a1bd171e5171740f0c946ff33fda61.scope: Deactivated successfully.1914machine # [ 63.881705] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-9faeca16da53fb1c89133f564488f85609a1bd171e5171740f0c946ff33fda61-rootfs.mount: Deactivated successfully.1915machine # [ 64.535493] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-9faeca16da53fb1c89133f564488f85609a1bd171e5171740f0c946ff33fda61-shm.mount: Deactivated successfully.1916machine # [ 64.594431] dhcpcd[2760]: veth58cba056: carrier lost[ 64.602227] cni0: port 2(veth58cba056) entered disabled state1917machine # 1918machine # [ 64.606361] veth58cba056 (unregistering): left allmulticast mode1919machine # [ 64.606396] veth58cba056 (unregistering): left promiscuous mode1920machine # [ 64.606412] cni0: port 2(veth58cba056) entered disabled state1921machine # [ 64.645082] systemd[1]: run-netns-cni\x2d4505147b\x2df544\x2d72ab\x2d833f\x2d8aea9f553d78.mount: Deactivated successfully.1922machine # [ 64.656746] dhcpcd[2760]: veth58cba056: deleting address fe80::80e5:3fff:feb7:b3061923machine # [ 64.709887] dhcpcd[2760]: veth58cba056: removing interface1924machine # NAME: niks31925machine # LAST DEPLOYED: Thu Nov 12 16:58:00 20261926machine # NAMESPACE: niks31927machine # STATUS: deployed1928machine # REVISION: 11929machine # DESCRIPTION: Install complete1930machine # TEST SUITE: niks3-test1931machine # Last Started: Thu Nov 12 16:58:16 20261932machine # Last Completed: Thu Nov 12 16:58:19 20261933machine # Phase: Succeeded1934[65.49s] machine: (finished: must succeed: helm test -n niks3 niks3 --timeout 2m >&2, in 3.87 seconds)1935[65.49s] (finished: subtest: helm test hook passes, in 3.87 seconds)1936[65.49s] (finished: run the VM test script, in 65.48 seconds)1937machine # [ 64.808593] k3s[831]: I1112 16:58:19.573187 831 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="9faeca16da53fb1c89133f564488f85609a1bd171e5171740f0c946ff33fda61"1938machine # [ 64.815619] systemd[1]: Removed slice libcontainer container kubepods-besteffort-pod169b4551_c90d_4e27_acbe_7c533e9b5776.slice.1939machine # [ 64.817786] systemd[1]: kubepods-besteffort-pod169b4551_c90d_4e27_acbe_7c533e9b5776.slice: Consumed 77ms CPU time over 3.343s wall clock time, 16.1M memory peak, 693B incoming IP traffic, 495B outgoing IP traffic.1940[66.09s] test script finished in 66.09s1941[66.09s] cleanup1942[66.09s] kill QemuMachine (pid 45)1943machine # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/lq2fsnmg0q3y0vlxn91w8s8wvj1m6fld-python3-3.14.8/bin/python3.14)1944machine # [2026-11-12T16:58:19Z INFO virtiofsd] Client disconnected, shutting down1945machine # [2026-11-12T16:58:19Z INFO virtiofsd] Client disconnected, shutting down1946machine # [2026-11-12T16:58:19Z INFO virtiofsd] Client disconnected, shutting down1947[66.96s] (finished: cleanup, in 0.87 seconds)1948additionally exposed symbols:1949 machine,1950 vlan1,1951 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_ssh1952time=2026-11-12T16:58:08.643Z level=INFO msg="Uploading 8 paths to localhost (0 already cached)"1953time=2026-11-12T16:58:08.643Z level=INFO msg="Uploading 09mqjwlgdr2jchjchwpgff2vryn4zc4q-xgcc-16.2.0-libgcc (150.2KB)"1954time=2026-11-12T16:58:08.643Z level=INFO msg="Uploading 7kfrkscfmm8p09q9w392p86rxqji8cbf-mailcap-2.1.54 (116.6KB)"1955time=2026-11-12T16:58:08.644Z level=INFO msg="Uploading vr8lx1cjz6zw4xhmb4k405v6cqrkslnk-libunistring-1.4.2 (2.0MB)"1956time=2026-11-12T16:58:08.644Z level=INFO msg="Uploading ad9h5b41f7x4fvk22axfjvxykisyjc15-tzdata-2026e (2.0MB)"1957time=2026-11-12T16:58:08.645Z level=INFO msg="Uploading an044afijna5agsc71nj88va0jbxiq27-niks3-1.17.1 (7.2MB)"1958time=2026-11-12T16:58:08.644Z level=INFO msg="Uploading nhphqkv18x8fpf3flz0bsm1h554pawn7-glibc-2.44-57 (44.8MB)"1959time=2026-11-12T16:58:08.644Z level=INFO msg="Uploading wsn07qxxn13gcdcjw5avz47j8lb2zpdv-libidn2-2.3.8 (366.1KB)"1960time=2026-11-12T16:58:08.648Z level=INFO msg="Uploading a9l8h2d532wk9zpyvl3qms0v5iwbjp67-iana-etc-20251215 (557.8KB)"1961time=2026-11-12T16:58:09.471Z level=INFO msg="Uploading 8 narinfos"1962time=2026-11-12T16:58:09.517Z level=INFO msg="Upload complete. (958ms)"1963