tribuchet: building on eliza Machine state will be reset. To keep it, pass --keep-machine-state start all VLans (finished: start all VLans, in 0.00 seconds) Test will time out and terminate in 3600.0 seconds run the VM test script machine: waiting for unit k3s.service machine: waiting for the VM to finish booting machine: starting vm machine: QEMU running (pid 45) machine # Disk image does not exist, creating the virtualisation disk image... machine # Formatting '/build/vm-state-machine/tmp.4eY8Kmy7ZA', fmt=raw size=8589934592 machine # mke2fs 1.47.4 (6-Mar-2025) machine # Discarding device blocks: 0/2097152 done machine # Creating filesystem with 2097152 4k blocks and 524288 inodes machine # Filesystem UUID: 1f8978cb-86fd-4357-98ef-44c18f01b7cc machine # Superblock backups stored on blocks: machine # 32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632 machine # machine # Allocating group tables: 0/64 done machine # Writing inode tables: 0/64 done machine # Creating journal (16384 blocks): done machine # Writing superblocks and filesystem accounting information: 0/64 done machine # machine # Virtualisation disk image created. machine # Starting virtiofs daemons... machine # [2026-10-01T08:24:00Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1) machine # [2026-10-01T08:24:00Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether machine # [2026-10-01T08:24:00Z INFO virtiofsd] Waiting for vhost-user socket connection... machine # [2026-10-01T08:24:00Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1) machine # [2026-10-01T08:24:00Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether machine # [2026-10-01T08:24:00Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1) machine # [2026-10-01T08:24:00Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether machine # [2026-10-01T08:24:00Z INFO virtiofsd] Waiting for vhost-user socket connection... machine # [2026-10-01T08:24:00Z INFO virtiofsd] Waiting for vhost-user socket connection... machine # [2026-10-01T08:24:00Z INFO virtiofsd] Client connected, servicing requests machine # [2026-10-01T08:24:00Z INFO virtiofsd] Client connected, servicing requests machine # [2026-10-01T08:24:00Z INFO virtiofsd] Client connected, servicing requests machine # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40] machine # [ 0.000000] Linux version 6.18.54 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Fri Sep 25 14:35:54 UTC 2026 machine # [ 0.000000] KASLR enabled machine # [ 0.000000] random: crng init done machine # [ 0.000000] Machine model: linux,dummy-virt machine # [ 0.000000] efi: UEFI not found. machine # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT machine # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000ffffffff] machine # [ 0.000000] NODE_DATA(0) allocated [mem 0xffded0c0-0xffdf083f] machine # [ 0.000000] Zone ranges: machine # [ 0.000000] DMA [mem 0x0000000040000000-0x00000000ffffffff] machine # [ 0.000000] DMA32 empty machine # [ 0.000000] Normal empty machine # [ 0.000000] Device empty machine # [ 0.000000] Movable zone start for each node machine # [ 0.000000] Early memory node ranges machine # [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000ffffffff] machine # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x00000000ffffffff] machine # [ 0.000000] cma: Reserved 32 MiB at 0x00000000fac00000 machine # [ 0.000000] psci: probing for conduit method from DT. machine # [ 0.000000] psci: PSCIv1.3 detected in firmware. machine # [ 0.000000] psci: Using standard PSCI v0.2 function IDs machine # [ 0.000000] psci: Trusted OS migration not required machine # [ 0.000000] psci: SMC Calling Convention v1.1 machine # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003) machine # [ 0.000000] percpu: Embedded 76 pages/cpu s186776 r8192 d116328 u311296 machine # [ 0.000000] Detected PIPT I-cache on CPU0 machine # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm) machine # [ 0.000000] CPU features: detected: GICv3 CPU interface machine # [ 0.000000] CPU features: detected: Spectre-v4 machine # [ 0.000000] CPU features: detected: Spectre-BHB machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38 machine # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23 machine # [ 0.000000] alternatives: applying boot alternatives machine # [ 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/82mp4hd9lpknzd1rcd0j4xk7yajj5w7m-nixos-system-machine-test/init regInfo=/nix/.ro-store/8ipfh69a2il2lsaj6d0chy8p1q2ldfff-closure-info/registration console=ttyAMA0,115200n8 console=tty0 machine # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/8ipfh69a2il2lsaj6d0chy8p1q2ldfff-closure-info/registration", will be passed to user space. machine # [ 0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes machine # [ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) machine # [ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 3MB machine # [ 0.000000] software IO TLB: area num 2. machine # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size roundup to 4MB machine # [ 0.000000] software IO TLB: mapped [mem 0x00000000fa200000-0x00000000fa600000] (4MB) machine # [ 0.000000] Fallback order for Node 0: 0 machine # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 786432 machine # [ 0.000000] Policy zone: DMA machine # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off machine # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1 machine # [ 0.000000] allocated 6291456 bytes of page_ext machine # [ 0.000000] ftrace: allocating 74966 entries in 294 pages machine # [ 0.000000] ftrace: allocated 294 pages with 4 groups machine # [ 0.000000] rcu: Hierarchical RCU implementation. machine # [ 0.000000] rcu: RCU event tracing is enabled. machine # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=2. machine # [ 0.000000] Trampoline variant of Tasks RCU enabled. machine # [ 0.000000] Rude variant of Tasks RCU enabled. machine # [ 0.000000] Tracing variant of Tasks RCU enabled. machine # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. machine # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2 machine # [ 0.000000] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2. machine # [ 0.000000] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2. machine # [ 0.000000] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2. machine # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 machine # [ 0.000000] GICv3: 256 SPIs implemented machine # [ 0.000000] GICv3: 0 Extended SPIs implemented machine # [ 0.000000] Root IRQ handler: gic_handle_irq machine # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI machine # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0 machine # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000 machine # [ 0.000000] ITS [mem 0x08080000-0x0809ffff] machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @45100000 (indirect, esz 8, psz 64K, shr 1) machine # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @45110000 (flat, esz 8, psz 64K, shr 1) machine # [ 0.000000] GICv3: using LPI property table @0x0000000045130000 machine # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000045140000 machine # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention. machine # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns machine # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt). machine # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns machine # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns machine # [ 0.000030] arm-pv: using stolen time PV machine # [ 0.000368] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____) machine # [ 0.000546] Console: colour dummy device 80x25 machine # [ 0.000555] printk: legacy console [tty0] enabled machine # [ 0.000749] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000) machine # [ 0.000755] pid_max: default: 32768 minimum: 301 machine # [ 0.000832] LSM: initializing lsm=capability,landlock,yama,bpf,ima machine # [ 0.000958] landlock: Up and running. machine # [ 0.000960] Yama: becoming mindful. machine # [ 0.001352] LSM support for eBPF active machine # [ 0.001514] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) machine # [ 0.001576] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) machine # [ 0.003714] rcu: Hierarchical SRCU implementation. machine # [ 0.003719] rcu: Max phase no-delay instances is 1000. machine # [ 0.003888] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level machine # [ 0.005058] fsl-mc MSI: its@8080000 domain created machine # [ 0.005183] EFI services will not be available. machine # [ 0.005285] smp: Bringing up secondary CPUs ... machine # [ 0.005862] Detected PIPT I-cache on CPU1 machine # [ 0.005930] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000 machine # [ 0.006004] GICv3: CPU1: using allocated LPI pending table @0x0000000045150000 machine # [ 0.006078] CPU1: Booted secondary processor 0x0000000001 [0xc00fac40] machine # [ 0.006464] smp: Brought up 1 node, 2 CPUs machine # [ 0.006477] SMP: Total of 2 processors activated. machine # [ 0.006480] CPU: All CPU(s) started at EL1 machine # [ 0.006490] CPU features: detected: Branch Target Identification machine # [ 0.006494] CPU features: detected: ARMv8.4 Translation Table Level machine # [ 0.006497] CPU features: detected: Instruction cache invalidation not required for I/D coherence machine # [ 0.006500] CPU features: detected: Data cache clean to the PoU not required for I/D coherence machine # [ 0.006503] CPU features: detected: Common not Private translations machine # [ 0.006506] CPU features: detected: CRC32 instructions machine # [ 0.006509] CPU features: detected: Data cache clean to Point of Deep Persistence machine # [ 0.006512] CPU features: detected: Data cache clean to Point of Persistence machine # [ 0.006515] CPU features: detected: Data independent timing control (DIT) machine # [ 0.006518] CPU features: detected: E0PD machine # [ 0.006520] CPU features: detected: Enhanced Counter Virtualization machine # [ 0.006523] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF) machine # [ 0.006526] CPU features: detected: Enhanced Virtualization Traps machine # [ 0.006529] CPU features: detected: Fine Grained Traps machine # [ 0.006532] CPU features: detected: Generic authentication (architected QARMA5 algorithm) machine # [ 0.006536] CPU features: detected: RCpc load-acquire (LDAPR) machine # [ 0.006539] CPU features: detected: LSE atomic instructions machine # [ 0.006542] CPU features: detected: Privileged Access Never machine # [ 0.006544] CPU features: detected: PMUv3 machine # [ 0.006547] CPU features: detected: RAS Extension Support machine # [ 0.006549] CPU features: detected: RASv1p1 Extension Support machine # [ 0.006552] CPU features: detected: Random Number Generator machine # [ 0.006554] CPU features: detected: Speculation barrier (SB) machine # [ 0.006556] CPU features: detected: Stage-2 Force Write-Back machine # [ 0.006559] CPU features: detected: TLB range maintenance instructions machine # [ 0.006563] CPU features: detected: Speculative Store Bypassing Safe (SSBS) machine # [ 0.006653] alternatives: applying system-wide alternatives machine # [ 0.009648] CPU features: detected: BBM Level 2 without TLB conflict abort machine # [ 0.009849] Memory: 2944196K/3145728K available (24448K kernel code, 7094K rwdata, 26596K rodata, 4736K init, 1107K bss, 154876K reserved, 32768K cma-reserved) machine # [ 0.010953] devtmpfs: initialized machine # [ 0.013632] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear) machine # [ 0.013691] futex hash table entries: 512 (32768 bytes on 1 NUMA nodes, total 32 KiB, linear). machine # [ 0.013925] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL machine # [ 0.013936] 0 pages in range for non-PLT usage machine # [ 0.013938] 508224 pages in range for PLT usage machine # [ 0.014072] pinctrl core: initialized pinctrl subsystem machine # [ 0.015033] DMI not present or invalid. machine # [ 0.018373] NET: Registered PF_NETLINK/PF_ROUTE protocol family machine # [ 0.020982] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations machine # [ 0.021289] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations machine # [ 0.021628] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations machine # [ 0.021661] audit: initializing netlink subsys (disabled) machine # [ 0.022157] audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1 machine # [ 0.023498] thermal_sys: Registered thermal governor 'fair_share' machine # [ 0.023506] thermal_sys: Registered thermal governor 'bang_bang' machine # [ 0.023516] thermal_sys: Registered thermal governor 'step_wise' machine # [ 0.023520] thermal_sys: Registered thermal governor 'user_space' machine # [ 0.023524] thermal_sys: Registered thermal governor 'power_allocator' machine # [ 0.023604] cpuidle: using governor ladder machine # [ 0.023626] cpuidle: using governor menu machine # [ 0.024093] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers. machine # [ 0.024158] ASID allocator initialised with 65536 entries machine # [ 0.026334] Serial: AMBA PL011 UART driver machine # [ 0.035807] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1 machine # [ 0.036031] printk: console [ttyAMA0] enabled machine # [ 0.062213] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages machine # [ 0.062227] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page machine # [ 0.062230] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages machine # [ 0.062233] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page machine # [ 0.062236] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages machine # [ 0.062239] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page machine # [ 0.062242] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages machine # [ 0.062244] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page machine # [ 0.071001] fbcon: Taking over console machine # [ 0.071015] ACPI: Interpreter disabled. machine # [ 0.072089] iommu: Default domain type: Translated machine # [ 0.072095] iommu: DMA domain TLB invalidation policy: strict mode machine # [ 0.079136] SCSI subsystem initialized machine # [ 0.084381] usbcore: registered new interface driver usbfs machine # [ 0.084410] usbcore: registered new interface driver hub machine # [ 0.084433] usbcore: registered new device driver usb machine # [ 0.084806] pps_core: LinuxPPS API ver. 1 registered machine # [ 0.084811] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti machine # [ 0.084820] PTP clock support registered machine # [ 0.084866] EDAC MC: Ver: 3.0.0 machine # [ 0.085103] scmi_core: SCMI protocol bus registered machine # [ 0.085698] FPGA manager framework machine # [ 0.086468] vgaarb: loaded machine # [ 0.089463] clocksource: Switched to clocksource arch_sys_counter machine # [ 0.094414] VFS: Disk quotas dquot_6.6.0 machine # [ 0.094465] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) machine # [ 0.094890] netfs: FS-Cache loaded machine # [ 0.095063] pnp: PnP ACPI: disabled machine # [ 0.098845] NET: Registered PF_INET protocol family machine # [ 0.099483] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) machine # [ 0.132124] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) machine # [ 0.132177] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) machine # [ 0.132216] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) machine # [ 0.132404] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) machine # [ 0.132681] TCP: Hash tables configured (established 32768 bind 32768) machine # [ 0.132796] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear) machine # [ 0.132842] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear) machine # [ 0.132906] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear) machine # [ 0.133027] NET: Registered PF_UNIX/PF_LOCAL protocol family machine # [ 0.133084] NET: Registered PF_XDP protocol family machine # [ 0.133102] PCI: CLS 0 bytes, default 64 machine # [ 0.133385] Trying to unpack rootfs image as initramfs... machine # [ 0.145557] kvm [1]: HYP mode not available machine # [ 0.226347] Initialise system trusted keyrings machine # [ 0.230161] workingset: timestamp_bits=42 max_order=20 bucket_order=0 machine # [ 0.230665] squashfs: version 4.0 (2009/01/31) Phillip Lougher machine # [ 0.230731] 9p: Installing v9fs 9p2000 file system support machine # [ 0.245060] Key type asymmetric registered machine # [ 0.245066] Asymmetric key parser 'x509' registered machine # [ 0.245166] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242) machine # [ 0.247662] io scheduler mq-deadline registered machine # [ 0.247666] io scheduler kyber registered machine # [ 0.257890] pl061_gpio 9030000.pl061: PL061 GPIO chip registered machine # [ 0.262426] ledtrig-cpu: registered to indicate activity on CPUs machine # [ 0.263072] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges: machine # [ 0.263099] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000 machine # [ 0.263118] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000 machine # [ 0.263125] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000 machine # [ 0.263147] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits machine # [ 0.263173] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff] machine # [ 0.263322] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00 machine # [ 0.263330] pci_bus 0000:00: root bus resource [bus 00-ff] machine # [ 0.263335] pci_bus 0000:00: root bus resource [io 0x0000-0xffff] machine # [ 0.263338] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff] machine # [ 0.263341] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff] machine # [ 0.263411] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint machine # [ 0.263913] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint machine # [ 0.264119] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f] machine # [ 0.264133] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.264161] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.264174] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref] machine # [ 0.264697] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint machine # [ 0.264900] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f] machine # [ 0.264912] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.264940] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.287550] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint machine # [ 0.287741] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f] machine # [ 0.287753] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.287783] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.288297] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint machine # [ 0.288487] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f] machine # [ 0.288498] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.288524] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.288536] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref] machine # [ 0.289021] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint machine # [ 0.289216] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.289243] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.300297] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint machine # [ 0.300490] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.300515] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.300931] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint machine # [ 0.301118] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff] machine # [ 0.301406] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint machine # [ 0.307241] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.307268] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.307747] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint machine # [ 0.307933] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.307959] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.308432] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint machine # [ 0.308618] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.308643] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.309116] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint machine # [ 0.309399] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f] machine # [ 0.309411] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.309436] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.320349] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint machine # [ 0.320531] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f] machine # [ 0.320542] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff] machine # [ 0.320567] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref] machine # [ 0.321167] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned machine # [ 0.321173] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned machine # [ 0.321177] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned machine # [ 0.321219] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned machine # [ 0.321262] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned machine # [ 0.321304] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned machine # [ 0.321347] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned machine # [ 0.321391] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned machine # [ 0.321435] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned machine # [ 0.333940] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned machine # [ 0.333984] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned machine # [ 0.334028] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned machine # [ 0.334115] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned machine # [ 0.334158] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned machine # [ 0.334177] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned machine # [ 0.334198] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned machine # [ 0.334216] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned machine # [ 0.334233] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned machine # [ 0.334252] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned machine # [ 0.334270] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned machine # [ 0.334288] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned machine # [ 0.334306] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned machine # [ 0.334324] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned machine # [ 0.334342] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned machine # [ 0.334360] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned machine # [ 0.334377] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned machine # [ 0.334394] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned machine # [ 0.334411] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned machine # [ 0.334428] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned machine # [ 0.334445] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned machine # [ 0.334462] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned machine # [ 0.334484] pci_bus 0000:00: resource 4 [io 0x0000-0xffff] machine # [ 0.334489] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff] machine # [ 0.334492] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff] machine # [ 0.335350] pci 0000:00:07.0: enabling device (0000 -> 0002) machine # [ 0.364592] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003) machine # [ 0.367049] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003) machine # [ 0.369314] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003) machine # [ 0.371717] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003) machine # [ 0.374398] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002) machine # [ 0.379182] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002) machine # [ 0.381065] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002) machine # [ 0.383170] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002) machine # [ 0.385162] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002) machine # [ 0.387362] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003) machine # [ 0.392627] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003) machine # [ 0.397970] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled machine # [ 0.399838] msm_serial: driver initialized machine # [ 0.399975] SuperH (H)SCI(F) driver initialized machine # [ 0.400034] STM32 USART driver initialized machine # [ 0.432481] loop: module loaded machine # [ 0.432773] virtio_blk virtio2: 2/0/0 default/read/poll queues machine # [ 0.435670] virtio_blk virtio2: [vda] 16777216 512-byte logical blocks (8.59 GB/8.00 GiB) machine # [ 0.439348] megasas: 07.734.00.00-rc1 machine # [ 0.440218] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff] machine # [ 0.446919] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000 machine # [ 0.446951] Intel/Sharp Extended Query Table at 0x0031 machine # [ 0.449232] Using buffer write method machine # [ 0.449324] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff] machine # [ 0.456293] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000 machine # [ 0.456320] Intel/Sharp Extended Query Table at 0x0031 machine # [ 0.460415] Using buffer write method machine # [ 0.460442] Concatenating MTD devices: machine # [ 0.460445] (0): "0.flash" machine # [ 0.460448] (1): "0.flash" machine # [ 0.460450] into device "0.flash" machine # [ 0.665275] Freeing initrd memory: 26968K machine # [ 0.675669] tun: Universal TUN/TAP device driver, 1.6 machine # [ 0.681332] thunder_xcv, ver 1.0 machine # [ 0.681375] thunder_bgx, ver 1.0 machine # [ 0.681410] nicpf, ver 1.0 machine # [ 0.682384] e1000: Intel(R) PRO/1000 Network Driver machine # [ 0.682391] e1000: Copyright (c) 1999-2006 Intel Corporation. machine # [ 0.682425] e1000e: Intel(R) PRO/1000 Network Driver machine # [ 0.682433] e1000e: Copyright(c) 1999 - 2015 Intel Corporation. machine # [ 0.682470] igb: Intel(R) Gigabit Ethernet Network Driver machine # [ 0.682475] igb: Copyright (c) 2007-2014 Intel Corporation. machine # [ 0.682519] igbvf: Intel(R) Gigabit Virtual Function Network Driver machine # [ 0.682525] igbvf: Copyright (c) 2009 - 2012 Intel Corporation. machine # [ 0.682791] sky2: driver version 1.30 machine # [ 0.685564] usbcore: registered new interface driver usb-storage machine # [ 0.685699] usbcore: registered new interface driver usbserial_generic machine # [ 0.685720] usbserial: USB Serial support registered for generic machine # [ 0.686256] ehci-pci 0000:00:07.0: EHCI Host Controller machine # [ 0.686284] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1 machine # [ 0.686515] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000 machine # [ 0.686843] hv_vmbus: registering driver hyperv_keyboard machine # [ 0.688417] rtc-pl031 9010000.pl031: registered as rtc0 machine # [ 0.688454] rtc-pl031 9010000.pl031: setting system clock to 2026-10-01T08:24:01 UTC (1790843041) machine # [ 0.688982] i2c_dev: i2c /dev entries driver machine # [ 0.694317] sdhci: Secure Digital Host Controller Interface driver machine # [ 0.694328] sdhci: Copyright(c) Pierre Ossman machine # [ 0.694925] Synopsys Designware Multimedia Card Interface Driver machine # [ 0.695576] sdhci-pltfm: SDHCI platform and OF driver helper machine # [ 0.698247] hid: raw HID events driver (C) Jiri Kosina machine # [ 0.698713] usbcore: registered new interface driver usbhid machine # [ 0.698719] usbhid: USB HID core driver machine # [ 0.700494] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00 machine # [ 0.701059] hub 1-0:1.0: USB hub found machine # [ 0.701083] hub 1-0:1.0: 6 ports detected machine # [ 0.702488] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available machine # [ 0.705116] drop_monitor: Initializing network drop monitor service machine # [ 0.705387] NET: Registered PF_INET6 protocol family machine # [ 0.706366] Segment Routing with IPv6 machine # [ 0.706385] In-situ OAM (IOAM) with IPv6 machine # [ 0.706478] NET: Registered PF_PACKET protocol family machine # [ 0.706607] 9pnet: Installing 9P2000 support machine # [ 0.706664] Key type dns_resolver registered machine # [ 0.716888] registered taskstats version 1 machine # [ 0.717117] Loading compiled-in X.509 certificates machine # [ 0.732050] Demotion targets for Node 0: null machine # [ 0.732240] Key type .fscrypt registered machine # [ 0.732245] Key type fscrypt-provisioning registered machine # [ 0.732373] ima: No TPM chip found, activating TPM-bypass! machine # [ 0.732392] ima: Allocated hash algorithm: sha1 machine # [ 0.732428] ima: No architecture policies found machine # [ 0.733296] input: gpio-keys as /devices/platform/gpio-keys/input/input0 machine # [ 0.761598] clk: Disabling unused clocks machine # [ 0.761616] PM: genpd: Disabling unused power domains machine # [ 0.765106] Freeing unused kernel memory: 4736K machine # [ 0.765327] Run /init as init process machine # [ 0.788930] systemd[1]: Successfully made /usr/ read-only. machine # [ 0.949627] usb 1-1: new high-speed USB device number 2 using ehci-pci machine # [ 1.099398] 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/input1 machine # [ 1.123068] systemd[1]: systemd 261.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE) machine # [ 1.123098] systemd[1]: Detected virtualization qemu. machine # [ 1.123141] systemd[1]: Detected architecture arm64. machine # [ 1.123149] systemd[1]: Running in initrd. machine # [ 1.123674] systemd[1]: Initializing machine ID from random generator. machine # [ 1.123823] systemd[1]: Hostname set to . machine # [ 1.217551] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0 machine # [ 1.331150] systemd[1]: bpf-restrict-fs: LSM BPF program attached machine # [ 1.338293] usb 1-2: new high-speed USB device number 3 using ehci-pci machine # [ 1.393951] systemd[1]: Queued start job for default target Initrd Default Target. machine # [ 1.412835] systemd[1]: Created slice Slice /system/modprobe. machine # [ 1.413108] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. machine # [ 1.413149] systemd[1]: Expecting device /dev/disk/by-label/nixos... machine # [ 1.413178] systemd[1]: Reached target Path Units. machine # [ 1.413198] systemd[1]: Reached target Slice Units. machine # [ 1.413216] systemd[1]: Reached target Swaps. machine # [ 1.413235] systemd[1]: Reached target Timer Units. machine # [ 1.413426] systemd[1]: Listening on D-Bus System Message Bus Socket. machine # [ 1.413775] systemd[1]: Listening on Journal Socket (/dev/log). machine # [ 1.413957] systemd[1]: Listening on Journal Sockets. machine # [ 1.414120] systemd[1]: Listening on udev Control Socket. machine # [ 1.414260] systemd[1]: Listening on udev Kernel Socket. machine # [ 1.414283] systemd[1]: Reached target Socket Units. machine # [ 1.416310] systemd[1]: Starting Create List of Static Device Nodes... machine # [ 1.416397] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs machine # [ 1.422778] systemd[1]: Mounting Kernel Configuration File System... machine # [ 1.437818] systemd[1]: Starting Journal Service... machine # [ 1.444570] systemd[1]: Starting Load Kernel Modules... machine # [ 1.444738] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os machine # [ 1.457269] systemd[1]: Starting Coldplug All udev Devices... machine # [ 1.463379] systemd[1]: Finished Create List of Static Device Nodes. machine # [ 1.477908] systemd[1]: Starting Create Static Device Nodes in /dev gracefully... machine # [ 1.481336] systemd[1]: Mounted Kernel Configuration File System. machine # [ 1.489080] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. machine # [ 1.489390] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev machine # [ 1.493724] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0 machine # [ 1.494065] [drm] features: -virgl +edid -resource_blob -host_visible machine # [ 1.494070] [drm] features: -context_init machine # [ 1.494922] [drm] number of scanouts: 1 machine # [ 1.494935] [drm] number of cap sets: 0 machine # [ 1.501438] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic machine # [ 1.501459] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0 machine # [ 1.510582] 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/input2 machine # [ 1.513366] systemd-journald[79]: Collecting audit messages is disabled. machine # [ 1.516697] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0 machine # [ 1.528575] Console: switching to colour frame buffer device 160x50 machine # [ 1.529157] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device machine # [ 1.530768] systemd[1]: Finished Create Static Device Nodes in /dev gracefully. machine # [ 1.533042] systemd[1]: Starting Create Static Device Nodes in /dev... machine # [ 1.561913] systemd[1]: Finished Load Kernel Modules. machine # [ 1.571143] systemd-modules-load[80]: Using 2 probe threads machine # [ 1.573601] systemd[1]: Starting Apply Kernel Variables... machine # [ 1.576036] systemd[1]: Started Journal Service. machine # [ 1.574712] systemd-modules-load[80]: Module 'virtio_balloon' is built in machine # [ 1.575910] systemd-modules-load[80]: Module 'virtio_console' is built in machine # [ 1.577113] systemd-modules-load[80]: Inserted module 'dm_mod' machine # [ 1.578135] systemd-modules-load[80]: Module 'virtio_rng' is built in machine # [ 1.579238] systemd-modules-load[80]: Inserted module 'virtio_gpu' machine # [ 1.584097] systemd[1]: Finished Create Static Device Nodes in /dev. machine # [ 1.585193] systemd[1]: Reached target Preparation for Local File Systems. machine # [ 1.586201] systemd[1]: Reached target Local File Systems. machine # [ 1.592319] systemd[1]: Starting Create System Files and Directories... machine # [ 1.596575] systemd[1]: Starting Rule-based Manager for Device Events and Files... machine # [ 1.623417] systemd[1]: Finished Apply Kernel Variables. machine # [ 1.641477] systemd[1]: Finished Create System Files and Directories. machine # [ 1.649428] systemd-udevd[94]: Using default interface naming scheme 'v261'. machine # [ 1.665660] systemd[1]: Started Rule-based Manager for Device Events and Files. machine # [ 1.696693] systemd[1]: Starting Virtual Console Setup... machine # [ 1.744963] systemd-vconsole-setup[112]: Configuration of first virtual console was skipped, ignoring remaining ones. machine # [ 1.748628] systemd[1]: Finished Virtual Console Setup. machine # [ 2.165855] systemd[1]: Finished Coldplug All udev Devices. machine # [ 2.167172] systemd[1]: Reached target System Initialization. machine # [ 2.168198] systemd[1]: Reached target Basic System. machine # [ 2.303164] (udev-worker)[122]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name. machine # [ 2.312543] (udev-worker)[107]: Network interface NamePolicy= disabled on kernel command line. machine # [ 2.315251] (udev-worker)[122]: Network interface NamePolicy= disabled on kernel command line. machine # [ 2.321919] systemd[1]: Found device /dev/disk/by-label/nixos. machine # [ 2.323460] systemd[1]: Reached target Initrd Root Device. machine # [ 2.328998] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos... machine # [ 2.381517] systemd-fsck[130]: nixos: clean, 12/524288 files, 58513/2097152 blocks machine # [ 2.386554] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos. machine # [ 2.460231] systemd[1]: Mounting /sysroot... machine # [ 2.495669] EXT4-fs (vda): mounted filesystem 1f8978cb-86fd-4357-98ef-44c18f01b7cc r/w with ordered data mode. Quota mode: none. machine # [ 2.494261] systemd[1]: Mounted /sysroot. machine # [ 2.496661] systemd[1]: Reached target Initrd Root File System. machine # [ 2.501913] systemd[1]: Mounting /sysroot/nix/.ro-store... machine # [ 2.504442] systemd[1]: Mounting /sysroot/nix/.rw-store... machine # [ 2.527465] systemd[1]: Mounting /sysroot/run... machine # [ 2.532331] systemd[1]: Mounting /sysroot/tmp/shared... machine # [ 2.562351] systemd[1]: Mounting /sysroot/tmp/xchg... machine # [ 2.564623] systemd[1]: Starting Mountpoints Configured in the Real Root... machine # [ 2.571468] systemd[1]: Mounted /sysroot/nix/.rw-store. machine # [ 2.577105] systemd[1]: Mounted /sysroot/run. machine # [ 2.590490] systemd-sysroot-fstab-check[144]: /sysroot should be mounted in the initrd, will request daemon-reload. machine # [ 2.619144] systemd[1]: Starting rw-sysroot-nix-store.service... machine # [ 2.631063] systemd[1]: Reload requested from client PID 144 ('systemd-sysroot') (unit initrd-parse-etc.service)... machine # [ 2.634790] systemd[1]: Reloading... machine # [ 2.669455] fuse: init (API version 7.45) machine # [ 2.827609] virtiofs virtio6: discovered new tag: nix-store machine # [ 2.862088] virtiofs virtio6: virtio_fs_setup_dax: No cache capability machine # [ 2.879317] virtiofs virtio7: discovered new tag: shared machine # [ 2.880177] virtiofs virtio7: virtio_fs_setup_dax: No cache capability machine # [ 2.885678] virtiofs virtio8: discovered new tag: xchg machine # [ 2.886551] virtiofs virtio8: virtio_fs_setup_dax: No cache capability machine # [ 2.930525] systemd[1]: Reloading finished in 295 ms. machine # [ 2.982736] systemd-sysroot-fstab-check[144]: Requesting initrd-fs.target/start/replace... machine # [ 2.988176] systemd[1]: Mounted /sysroot/nix/.ro-store. machine # [ 2.989082] systemd[1]: Mounted /sysroot/tmp/shared. machine # [ 2.989831] systemd[1]: Mounted /sysroot/tmp/xchg. machine # [ 2.990519] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully. machine # [ 2.991505] systemd[1]: Finished rw-sysroot-nix-store.service. machine # [ 2.996382] systemd-sysroot-fstab-check[144]: Requesting swap.target/start/replace... machine # [ 3.000423] systemd[1]: initrd-parse-etc.service: Deactivated successfully. machine # [ 3.001894] systemd[1]: Finished Mountpoints Configured in the Real Root. machine # [ 3.003063] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies. machine # [ 3.008747] systemd[1]: Starting rw-sysroot-nix-store.service... machine # [ 3.028974] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully. machine # [ 3.030895] systemd[1]: Finished rw-sysroot-nix-store.service. machine # [ 3.252745] (udev-worker)[101]: mtd0ro: Failed to find and pin callout binary "/nix/store/gnadg5slifq2r638xvz4pv6vrsdl9xkj-systemd-261.2/lib/udev/mtd_probe": No such file or directory machine # [ 3.258676] (udev-worker)[101]: 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 directory machine # [ 3.270825] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. machine # [ 3.272273] systemd[1]: Stopped Virtual Console Setup. machine # [ 3.276206] systemd[1]: Stopping Virtual Console Setup... machine # [ 3.277635] systemd[1]: Starting Virtual Console Setup... machine # [ 3.288665] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. machine # [ 3.290805] systemd[1]: Stopped Virtual Console Setup. machine # [ 3.295339] systemd[1]: Starting Virtual Console Setup... machine # [ 3.328339] systemd-vconsole-setup[182]: Configuration of first virtual console was skipped, ignoring remaining ones. machine # [ 3.330303] systemd[1]: Finished Virtual Console Setup. machine # [ 3.461286] systemd[1]: Mounting /sysroot/nix/store... machine # [ 3.524503] systemd[1]: Mounted /sysroot/nix/store. machine # [ 3.525837] systemd[1]: Reached target Initrd File Systems. machine # [ 3.528631] systemd[1]: Starting Find NixOS closure... machine # [ 3.532261] systemd[1]: Starting Create Volatile Files and Directories in the Real Root... machine # [ 3.565249] systemd[1]: Finished Create Volatile Files and Directories in the Real Root. machine # [ 3.569979] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully. machine # [ 3.582929] systemd[1]: Finished Find NixOS closure. machine # [ 3.585137] systemd[1]: Reached target Initrd Default Target. machine # [ 3.588268] systemd[1]: Starting Cleaning Up and Shutting Down Daemons... machine # [ 3.621936] systemd[1]: Stopped target Initrd Default Target. machine # [ 3.623562] systemd[1]: Stopped target Basic System. machine # [ 3.624976] systemd[1]: Stopped target Initrd Root Device. machine # [ 3.626256] systemd[1]: Stopped target Path Units. machine # [ 3.627394] systemd[1]: systemd-ask-password-console.path: Deactivated successfully. machine # [ 3.629877] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch. machine # [ 3.631621] systemd[1]: Stopped target Slice Units. machine # [ 3.632822] systemd[1]: Stopped target Socket Units. machine # [ 3.633994] systemd[1]: Stopped target System Initialization. machine # [ 3.635304] systemd[1]: Stopped target Swaps. machine # [ 3.636402] systemd[1]: Stopped target Timer Units. machine # [ 3.638528] systemd[1]: dbus.socket: Deactivated successfully. machine # [ 3.639854] systemd[1]: Closed D-Bus System Message Bus Socket. machine # [ 3.641250] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully. machine # [ 3.642811] systemd[1]: Stopped Find NixOS closure. machine # [ 3.643838] systemd[1]: Starting rw-sysroot-nix-store.service... machine # [ 3.645230] systemd[1]: systemd-sysctl.service: Deactivated successfully. machine # [ 3.646576] systemd[1]: Stopped Apply Kernel Variables. machine # [ 3.647646] systemd[1]: systemd-modules-load.service: Deactivated successfully. machine # [ 3.649187] systemd[1]: Stopped Load Kernel Modules. machine # [ 3.650207] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully. machine # [ 3.652511] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root. machine # [ 3.654062] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. machine # [ 3.655397] systemd[1]: Stopped Create System Files and Directories. machine # [ 3.656707] systemd[1]: Stopped target Local File Systems. machine # [ 3.657725] systemd[1]: Stopped target Preparation for Local File Systems. machine # [ 3.658894] systemd[1]: systemd-udev-trigger.service: Deactivated successfully. machine # [ 3.660167] systemd[1]: Stopped Coldplug All udev Devices. machine # [ 3.661216] systemd[1]: Stopping Rule-based Manager for Device Events and Files... machine # [ 3.662454] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. machine # [ 3.663682] systemd[1]: Stopped Virtual Console Setup. machine # [ 3.664612] systemd[1]: initrd-cleanup.service: Deactivated successfully. machine # [ 3.672695] systemd[1]: Finished Cleaning Up and Shutting Down Daemons. machine # [ 3.677918] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully. machine # [ 3.679193] systemd[1]: Finished rw-sysroot-nix-store.service. machine # [ 3.681549] systemd[1]: systemd-udevd.service: Deactivated successfully. machine # [ 3.682680] systemd[1]: Stopped Rule-based Manager for Device Events and Files. machine # [ 3.683797] systemd[1]: systemd-udevd.service: Consumed 1.818s CPU time over 2.085s wall clock time, 29M memory peak. machine # [ 3.685600] systemd[1]: systemd-udevd-control.socket: Deactivated successfully. machine # [ 3.686701] systemd[1]: Closed udev Control Socket. machine # [ 3.687474] systemd[1]: Starting Cleanup udev Database... machine # [ 3.688603] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. machine # [ 3.689777] systemd[1]: Stopped Create Static Device Nodes in /dev. machine # [ 3.690725] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully. machine # [ 3.691945] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully. machine # [ 3.693173] systemd[1]: kmod-static-nodes.service: Deactivated successfully. machine # [ 3.694223] systemd[1]: Stopped Create List of Static Device Nodes. machine # [ 3.755778] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. machine # [ 3.757795] systemd[1]: Finished Cleanup udev Database. machine # [ 3.759021] systemd[1]: Reached target Switch Root. machine # [ 3.760743] systemd[1]: Starting NixOS Activation... machine # [ 3.862062] initrd-nixos-activation-start[205]: booting system configuration /nix/store/82mp4hd9lpknzd1rcd0j4xk7yajj5w7m-nixos-system-machine-test machine # [ 3.903866] initrd-nixos-activation-start[205]: running activation script... machine # [ 4.192953] initrd-nixos-activation-start[228]: setting up /etc... machine # [ 4.323803] systemd[1]: initrd-nixos-activation.service: Deactivated successfully. machine # [ 4.325819] systemd[1]: Finished NixOS Activation. machine # [ 4.326889] systemd[1]: Starting Switch Root... machine # [ 4.352426] systemd[1]: Switching root. machine # [ 4.471881] systemd-journald[79]: Received SIGTERM from PID 1 (systemd). machine # [ 5.139122] systemd[1]: systemd 261.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE) machine # [ 5.139185] systemd[1]: Detected virtualization qemu. machine # [ 5.139243] systemd[1]: Detected architecture arm64. machine # [ 5.139366] systemd[1]: Detected first boot. machine # [ 5.141260] systemd[1]: Initializing machine ID from random generator. machine # [ 5.339307] systemd[1]: bpf-restrict-fs: LSM BPF program attached machine # [ 5.487812] systemd[1]: Applying preset policy. machine # [ 5.746518] systemd[1]: Populated /etc with preset unit settings. machine # [ 5.964792] systemd[1]: initrd-switch-root.service: Deactivated successfully. machine # [ 5.966051] systemd[1]: Stopped initrd-switch-root.service. machine # [ 5.968889] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. machine # [ 5.973851] systemd[1]: Created slice Slice /system/getty. machine # [ 5.976102] systemd[1]: Created slice User and Session Slice. machine # [ 5.976964] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. machine # [ 5.977797] systemd[1]: Started Forward Password Requests to Wall Directory Watch. machine # [ 5.978436] systemd[1]: Expecting device /dev/hvc0... machine # [ 5.979142] systemd[1]: Expecting device /dev/ttyAMA0... machine # [ 5.979758] systemd[1]: Reached target Local Encrypted Volumes. machine # [ 5.980366] systemd[1]: Stopped target initrd-fs.target. machine # [ 5.980996] systemd[1]: Stopped target initrd-root-fs.target. machine # [ 5.981900] systemd[1]: Stopped target initrd-switch-root.target. machine # [ 5.982528] systemd[1]: Reached target Virtual Machines and Containers. machine # [ 5.983171] systemd[1]: Reached target Path Units. machine # [ 5.983776] systemd[1]: Reached target Remote File Systems. machine # [ 5.984377] systemd[1]: Reached target Slice Units. machine # [ 5.984969] systemd[1]: Reached target Swaps. machine # [ 5.999303] systemd[1]: Listening on Query the User Interactively for a Password. machine # [ 6.003447] systemd[1]: Listening on Process Core Dump Socket. machine # [ 6.005839] systemd[1]: Listening on Credential Encryption/Decryption. machine # [ 6.009872] systemd[1]: Listening on Factory Reset Management. machine # [ 6.010719] systemd[1]: Listening on Hostname Service Socket. machine # [ 6.016345] systemd[1]: Starting Journal Log Access Socket... machine # [ 6.017815] systemd[1]: Listening on Journal Audit Socket. machine # [ 6.022305] systemd[1]: Listening on Console Output Muting Service Socket. machine # [ 6.023440] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket. machine # [ 6.024157] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os machine # [ 6.024772] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki machine # [ 6.036784] systemd[1]: Listening on Disk Repartitioning Service Socket. machine # [ 6.037704] systemd[1]: Listening on udev Control Socket. machine # [ 6.038486] systemd[1]: Listening on udev Varlink Socket. machine # [ 6.044001] systemd[1]: Mounting Huge Pages File System... machine # [ 6.047906] systemd[1]: Mounting POSIX Message Queue File System... machine # [ 6.053095] systemd[1]: Mounting Kernel Debug File System... machine # [ 6.065698] systemd[1]: Mounting Kernel Trace File System... machine # [ 6.075655] systemd[1]: Starting Create List of Static Device Nodes... machine # [ 6.077683] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs machine # [ 6.087639] systemd[1]: Mounting Kernel Configuration File System... machine # [ 6.090384] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm machine # [ 6.090998] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore machine # [ 6.091728] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse machine # [ 6.098326] systemd[1]: Mounting FUSE Control File System... machine # [ 6.099252] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67 machine # [ 6.111406] systemd[1]: Starting Journal Service... machine # [ 6.127932] systemd[1]: Starting Load Kernel Modules... machine # [ 6.138685] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer... machine # [ 6.148411] systemd[1]: Starting Remount Root and Kernel File Systems... machine # [ 6.149061] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os machine # [ 6.161833] systemd[1]: Starting Coldplug All udev Devices... machine # [ 6.165251] systemd[1]: Listening on Journal Log Access Socket. machine # [ 6.166027] systemd[1]: Mounted Huge Pages File System. machine # [ 6.166665] systemd[1]: Mounted POSIX Message Queue File System. machine # [ 6.167294] systemd[1]: Mounted Kernel Debug File System. machine # [ 6.167953] systemd[1]: Mounted Kernel Trace File System. machine # [ 6.170256] systemd[1]: Finished Create List of Static Device Nodes. machine # [ 6.170927] systemd[1]: Mounted Kernel Configuration File System. machine # [ 6.177185] systemd[1]: Starting Create Static Device Nodes in /dev gracefully... machine # [ 6.184334] systemd[1]: Mounted FUSE Control File System. machine # [ 6.186404] systemd-journald[298]: Collecting audit messages is enabled. machine # [ 6.193426] systemd[1]: Queued start job for default target Multi-User System. machine # [ 6.198904] systemd[1]: Started Journal Service. machine # [ 6.196956] systemd[1]: systemd-journald.service: Deactivated successfully. machine # [ 6.220805] systemd-modules-load[299]: Using 2 probe threads machine # [ 6.234750] systemd-modules-load[299]: Module 'atkbd' is built in machine # [ 6.237713] systemd-modules-load[299]: Module 'loop' is built in machine # [ 6.246371] systemd[1]: Finished Load Kernel Modules. machine # [ 6.256197] EXT4-fs (vda): re-mounted 1f8978cb-86fd-4357-98ef-44c18f01b7cc. machine # [ 6.256594] systemd[1]: Starting Apply Kernel Variables... machine # [ 6.261629] systemd[1]: Finished Remount Root and Kernel File Systems. machine # [ 6.262687] systemd[1]: Listening on Disk Image Download Service Socket. machine # [ 6.272735] systemd[1]: Starting Flush Journal to Persistent Storage... machine # [ 6.280222] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore machine # [ 6.289731] systemd[1]: Starting Load/Save OS Random Seed... machine # [ 6.291100] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os machine # [ 6.301727] systemd-oomd[301]: No swap; memory pressure usage will be degraded machine # [ 6.307367] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer. machine # [ 6.346312] systemd[1]: Finished Create Static Device Nodes in /dev gracefully. machine # [ 6.365772] systemd-journald[298]: Received client request to flush runtime journal. machine # [ 6.417452] systemd[1]: Starting Create Static Device Nodes in /dev... machine # [ 6.420899] systemd[1]: Finished Apply Kernel Variables. machine # [ 6.422798] systemd[1]: Finished Load/Save OS Random Seed. machine # [ 6.423946] systemd[1]: Reached target First Boot Complete. machine # [ 6.425181] systemd[1]: Finished Flush Journal to Persistent Storage. machine # [ 6.434317] systemd[1]: Finished Create Static Device Nodes in /dev. machine # [ 6.435412] systemd[1]: Reached target Preparation for Local File Systems. machine # [ 6.437570] systemd[1]: Starting Rule-based Manager for Device Events and Files... machine # [ 6.496433] systemd-udevd[328]: Using default interface naming scheme 'v261'. machine # [ 6.531230] systemd[1]: Started Rule-based Manager for Device Events and Files. machine # [ 6.901322] systemd[1]: Finished Coldplug All udev Devices. machine # [ 6.957537] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs machine # [ 6.963830] systemd[1]: Mounting /run/wrappers... machine # [ 6.973899] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse machine # [ 6.996690] systemd[1]: Mounted /run/wrappers. machine # [ 6.997774] systemd[1]: Reached target Local File Systems. machine # [ 6.999715] systemd[1]: Listening on Boot Loader Control Service Socket. machine # [ 7.003361] systemd[1]: Starting register-nix-paths.service... machine # [ 7.007741] systemd[1]: Starting Create SUID/SGID Wrappers... machine # [ 7.012177] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met. machine # [ 7.019914] systemd[1]: Starting Save Transient machine-id to Disk... machine # [ 7.021255] systemd[1]: Starting Create System Files and Directories... machine # [ 7.087717] systemd[1]: etc-machine\x2did.mount: Deactivated successfully. machine # [ 7.094563] systemd[1]: Finished Save Transient machine-id to Disk. machine # [ 7.123237] systemd[1]: Condition check resulted in /dev/hvc0 being skipped. machine # [ 7.147389] systemd[1]: Finished Create System Files and Directories. machine # [ 7.180867] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped. machine # [ 7.188370] systemd[1]: Starting Rebuild Journal Catalog... machine # [ 7.192306] systemd[1]: Starting Record System Boot/Shutdown in UTMP... machine # [ 7.257579] systemd[1]: Finished Record System Boot/Shutdown in UTMP. machine # [ 7.301512] systemd[1]: Finished Rebuild Journal Catalog. machine # [ 7.308526] systemd[1]: Starting Update is Completed... machine # [ 7.371235] systemd[1]: Finished Update is Completed. machine # [ 7.385275] (udev-worker)[333]: Network interface NamePolicy= disabled on kernel command line. machine # [ 7.392342] (udev-worker)[349]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name. machine # [ 7.396931] (udev-worker)[349]: Network interface NamePolicy= disabled on kernel command line. machine # [ 7.476901] systemd[1]: Condition check resulted in Virtio network device being skipped. machine # [ 7.479594] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore machine # [ 7.484435] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met. machine # [ 7.485814] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67 machine # [ 7.490076] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore machine # [ 7.493893] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os machine # [ 7.496147] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os machine # [ 7.552434] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully. machine # [ 7.553714] systemd[1]: Finished Create SUID/SGID Wrappers. machine # [ 7.575118] systemd[1]: Finished register-nix-paths.service. machine # [ 7.579899] systemd[1]: Reached target System Initialization. machine # [ 7.584306] systemd[1]: Started Discard unused filesystem blocks once a week. machine # [ 7.586081] systemd[1]: Started Daily Cleanup of Temporary Directories. machine # [ 7.590483] systemd[1]: Reached target Timer Units. machine # [ 7.600640] systemd[1]: Listening on D-Bus System Message Bus Socket. machine # [ 7.601791] systemd[1]: Listening on Nix Daemon Socket. machine # [ 7.602666] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. machine # [ 7.603995] systemd[1]: Reached target Socket Units. machine # [ 7.604888] systemd[1]: Reached target Basic System. machine # [ 7.611609] systemd[1]: Started backdoor.service. machine # [ 7.617938] systemd[1]: Starting Import lastlog data into lastlog2 database... machine # [ 7.625658] systemd[1]: Starting Name Service Cache Daemon (nsncd)... machine # [ 7.634843] systemd[1]: Starting Post-Boot Actions... machine # [ 7.649104] systemd[1]: Started Reset console on configuration changes. machine # [ 7.660264] systemd[1]: Starting resolvconf update... machine # [ 7.661271] systemd[1]: Started rustfs.service. machine # [ 7.666515] systemd[1]: Starting rustfs-setup.service... machine # [ 7.667833] systemd[1]: Starting D-Bus System Message Bus... machine # connecting to host... machine # [ 7.726275] systemd[1]: Started Name Service Cache Daemon (nsncd). machine # [ 7.735478] nsncd[434]: Oct 01 08:24:08.541 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" machine # [ 7.748182] systemd[1]: Reached target Host and Network Name Lookups. machine # [ 7.752391] systemd[1]: Reached target User and Group Name Lookups. machine # [ 7.753544] systemd[1]: Starting User Login Management... machine # [ 7.761116] systemd[1]: Finished Post-Boot Actions. machine # [ 7.763642] systemd[1]: Finished Import lastlog data into lastlog2 database. machine: Guest shell says: b'Spawning backdoor root shell...\n' machine: connected to guest root shell machine: (connecting took 8.08 seconds) machine: (finished: waiting for the VM to finish booting, in 8.49 seconds) machine # [ 7.860976] dbus-broker-launch[441]: Looking up NSS user entry for 'systemd-timesync'... machine # [ 7.880450] dbus-broker-launch[441]: NSS returned no entry for 'systemd-timesync' machine # [ 7.885320] dbus-broker-launch[441]: Invalid user-name in /nix/store/7rk1l7vm612w5nnhdsq18is34jxr0icr-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" machine # [ 7.903081] systemd[1]: Started D-Bus System Message Bus. machine # [ 7.920423] mousedev: PS/2 mouse device common for all mice machine # [ 7.943555] dbus-broker-launch[441]: Ready machine # [ 7.972589] systemd-logind[452]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard) machine # [ 7.985002] systemd-logind[452]: Watching system buttons on /dev/input/event0 (gpio-keys) machine # [ 8.283172] systemd-logind[452]: New seat seat0. machine # [ 8.293948] systemd[1]: Stopped target Host and Network Name Lookups. machine # [ 8.295501] nsncd[542]: Oct 01 08:24:09.035 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" machine # [ 8.309698] systemd[1]: Stopping Host and Network Name Lookups... machine # [ 8.310712] systemd[1]: Stopped target User and Group Name Lookups. machine # [ 8.316978] systemd[1]: Stopping User and Group Name Lookups... machine # [ 8.323664] systemd[1]: Stopping Name Service Cache Daemon (nsncd)... machine # [ 8.326918] systemd[1]: nscd.service: Deactivated successfully. machine # [ 8.331413] systemd[1]: Stopped Name Service Cache Daemon (nsncd). machine # [ 8.334250] systemd[1]: Starting Name Service Cache Daemon (nsncd)... machine # [ 8.337308] systemd[1]: Finished resolvconf update. machine # [ 8.339237] systemd[1]: Reached target Preparation for Network. machine # [ 8.341010] systemd[1]: Starting DHCP Client... machine # [ 8.343003] systemd[1]: Starting Address configuration of eth1... machine # [ 8.346313] systemd[1]: Starting Extra networking commands.... machine # [ 8.352827] systemd[1]: Started Name Service Cache Daemon (nsncd). machine # [ 8.353898] systemd[1]: Started User Login Management. machine # [ 8.354638] systemd[1]: Reached target Host and Network Name Lookups. machine # [ 8.360421] systemd[1]: Reached target User and Group Name Lookups. machine # [ 8.361916] systemd[1]: Starting linger-users.service... machine # [ 8.380223] systemd[1]: linger-users.service: Deactivated successfully. machine # [ 8.384598] systemd[1]: Finished linger-users.service. machine # [ 8.417684] network-addresses-eth1-start[565]: adding address 192.168.1.1/24... done machine # [ 8.434463] network-addresses-eth1-start[565]: adding address 2001:db8:1::1/64... done machine # [ 8.460354] systemd[1]: Finished Address configuration of eth1. machine # [ 8.523062] dhcpcd[581]: dhcpcd-10.3.2 starting machine # [ 8.530613] dhcpcd[619]: dev: loaded udev machine # [ 8.558436] 8021q: 802.1Q VLAN Support v1.8 machine # [ 8.558854] 8021q: adding VLAN 0 to HW filter on device eth1 machine # [ 8.612972] cfg80211: Loading compiled-in X.509 certificates for regulatory database machine # [ 8.631969] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' machine # [ 8.632500] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' machine # [ 8.633415] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2 machine # [ 8.633804] cfg80211: failed to load regulatory.db machine # [ 8.678266] systemd[1]: Finished Extra networking commands.. machine # [ 8.679295] systemd[1]: Reached target Network. machine # [ 8.688980] systemd[1]: Starting PostgreSQL Server... machine # [ 8.693158] systemd[1]: Starting Permit User Sessions... machine # [ 8.732425] systemd[1]: Finished Permit User Sessions. machine # [ 8.739994] systemd[1]: Started Getty on tty1. machine # [ 8.741044] systemd[1]: Reached target Login Prompts. machine # [ 8.766826] dhcpcd[619]: eth0: waiting for carrier machine # [ 8.771113] 8021q: adding VLAN 0 to HW filter on device eth0 machine # [ 8.768158] dhcpcd[619]: eth0: carrier acquired machine # [ 8.788110] dhcpcd[619]: DUID 00:01:00:01:32:50:d5:29:52:54:00:12:34:56 machine # [ 8.789220] dhcpcd[619]: eth0: IAID 00:12:34:56 machine # [ 8.789892] dhcpcd[619]: eth0: adding address fe80::5054:ff:fe12:3456 machine # [ 8.934496] postgresql-pre-start[661]: The files belonging to this database system will be owned by user "postgres". machine # [ 8.936722] postgresql-pre-start[661]: This user must also own the server process. machine # [ 8.937849] postgresql-pre-start[661]: The database cluster will be initialized with locale "en_US.UTF-8". machine # [ 8.939148] postgresql-pre-start[661]: The default database encoding has accordingly been set to "UTF8". machine # [ 8.941459] postgresql-pre-start[661]: The default text search configuration will be set to "english". machine # [ 8.942764] postgresql-pre-start[661]: Data page checksums are enabled. machine # [ 8.943733] postgresql-pre-start[661]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok machine # [ 8.945227] postgresql-pre-start[661]: creating subdirectories ... ok machine # [ 8.946160] postgresql-pre-start[661]: selecting dynamic shared memory implementation ... posix machine # [ 9.031367] postgresql-pre-start[661]: selecting default "max_connections" ... 100 machine # [ 9.118092] postgresql-pre-start[661]: selecting default "shared_buffers" ... 128MB machine # [ 9.380969] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input3 machine # [ 9.408420] dhcpcd[619]: eth0: soliciting a DHCP lease machine # [ 9.420596] dhcpcd[619]: eth0: offered 10.0.2.15 from 10.0.2.2 machine # [ 9.436306] dhcpcd[619]: eth0: probing address 10.0.2.15/24 machine # [ 9.696544] systemd[1]: Starting Virtual Console Setup... machine # [ 9.715881] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. machine # [ 9.718796] systemd[1]: Stopped Virtual Console Setup. machine # [ 9.732761] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. machine # [ 9.735602] systemd[1]: Starting Virtual Console Setup... machine # [ 9.737775] systemd-logind[452]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard) machine # [ 9.872486] systemd-vconsole-setup[702]: Configuration of first virtual console was skipped, ignoring remaining ones. machine # [ 9.881204] systemd[1]: Finished Virtual Console Setup. machine # [ 9.954048] postgresql-pre-start[661]: selecting default time zone ... UTC machine # [ 9.955755] postgresql-pre-start[661]: creating configuration files ... ok machine # [ 10.203586] postgresql-pre-start[661]: running bootstrap script ... ok machine # [ 10.712262] dhcpcd[619]: eth0: soliciting an IPv6 router machine # [ 10.714503] dhcpcd[619]: eth0: Router Advertisement from fe80::2 machine # [ 10.715965] dhcpcd[619]: eth0: adding address fec0::5054:ff:fe12:3456/64 machine # [ 10.717680] dhcpcd[619]: eth0: adding route to fec0::/64 machine # [ 10.718878] dhcpcd[619]: eth0: adding default route via fe80::2 machine # [ 10.790542] postgresql-pre-start[661]: performing post-bootstrap initialization ... ok machine # [ 10.915047] postgresql-pre-start[661]: syncing data to disk ... ok machine # [ 10.916768] postgresql-pre-start[661]: initdb: warning: enabling "trust" authentication for local connections machine # [ 10.918939] postgresql-pre-start[661]: 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. machine # [ 10.922474] postgresql-pre-start[661]: Success. You can now start the database server using: machine # [ 10.924339] postgresql-pre-start[661]: pg_ctl -D /var/lib/postgresql/18 -l logfile start machine # [ 11.050509] postgres[721]: [721] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit machine # [ 11.053701] postgres[721]: [721] LOG: listening on IPv4 address "0.0.0.0", port 5432 machine # [ 11.055121] postgres[721]: [721] LOG: listening on IPv6 address "::", port 5432 machine # [ 11.056395] postgres[721]: [721] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432" machine # [ 11.063901] postgres[730]: [730] LOG: database system was shut down at 2026-10-01 08:24:11 GMT machine # [ 11.071918] postgres[721]: [721] LOG: database system is ready to accept connections machine # [ 11.075546] systemd[1]: Started PostgreSQL Server. machine # [ 11.081804] systemd[1]: Starting PostgreSQL Setup Scripts... machine # [ 11.315308] postgresql-setup-start[741]: CREATE DATABASE machine # [ 11.580903] postgresql-setup-start[749]: CREATE ROLE machine # [ 11.606810] postgresql-setup-start[757]: ALTER DATABASE machine # [ 11.615481] systemd[1]: Finished PostgreSQL Setup Scripts. machine # [ 11.617311] systemd[1]: Reached target PostgreSQL. machine # [ 15.018504] dhcpcd[619]: eth0: leased 10.0.2.15 for 86400 seconds machine # [ 15.018762] dhcpcd[619]: eth0: adding route to 10.0.2.0/24 machine # [ 15.018833] dhcpcd[619]: eth0: adding default route via 10.0.2.2 machine # [ 15.140258] systemd[1]: Started DHCP Client. machine # [ 15.141528] systemd[1]: Reached target Network is Online. machine # [ 15.144681] systemd[1]: Starting k3s service... machine # [ 15.223012] k3s[847]: time="2026-10-01T08:24:16Z" level=info msg="Acquiring lock file /var/lib/rancher/k3s/data/.lock" machine # [ 15.225490] k3s[847]: time="2026-10-01T08:24:16Z" level=info msg="Preparing data dir /var/lib/rancher/k3s/data/5d85999ad517c8ade07834e45aaf9a85f85fcc88eac84337a49e52ac8f651083" machine # [ 18.352569] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Starting k3s 1.36.4+k3s1 (4dedb15b)" machine # [ 18.397646] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdle=20, maxOpen=0, maxLifetime=0s, maxIdleTime=2m0s" machine # [ 18.400856] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Kine built with sqlite from github.com/mattn/go-sqlite3 version 3.53.3" machine # [ 18.403574] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Configuring database table schema and indexes, this may take a moment..." machine # [ 18.407588] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Database tables and indexes are up to date" machine # [ 18.410180] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Running startup VACUUM to reclaim disk space, this may take a moment..." machine # [ 18.413357] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Startup VACUUM completed successfully" machine # [ 18.420298] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Kine available at unix://kine.sock" machine # [ 18.422219] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]" machine # [ 18.424550] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="Datastore connection validated successfully, proceeding with bootstrap data generation" machine # [ 18.427143] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="generated self-signed CA certificate CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:19.2381383 +0000 UTC notAfter=2036-09-28 07:24:19.2381383 +0000 UTC" machine # [ 18.430795] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.434271] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.437794] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.441075] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.444183] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.447311] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.450390] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="generated self-signed CA certificate CN=k3s-server-ca@1790843059: notBefore=2026-10-01 07:24:19.2446674 +0000 UTC notAfter=2036-09-28 07:24:19.2446674 +0000 UTC" machine # [ 18.453475] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-server-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.456090] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=kube-scheduler signed by CN=k3s-server-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.458647] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=kube-controller-manager signed by CN=k3s-server-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.461281] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="generated self-signed CA certificate CN=k3s-request-header-ca@1790843059: notBefore=2026-10-01 07:24:19.24798454 +0000 UTC notAfter=2036-09-28 07:24:19.24798454 +0000 UTC" machine # [ 18.464033] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.466559] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="generated self-signed CA certificate CN=etcd-server-ca@1790843059: notBefore=2026-10-01 07:24:19.2493134 +0000 UTC notAfter=2036-09-28 07:24:19.2493134 +0000 UTC" machine # [ 18.469248] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.471622] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="generated self-signed CA certificate CN=etcd-peer-ca@1790843059: notBefore=2026-10-01 07:24:19.25057022 +0000 UTC notAfter=2036-09-28 07:24:19.25057022 +0000 UTC" machine # [ 18.474363] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.476757] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.523032] k3s[847]: time="2026-10-01T08:24:19Z" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1790843059: notBefore=2026-10-01 07:24:19 +0000 UTC notAfter=2027-10-01 07:24:19 +0000 UTC" machine # [ 18.533575] k3s[847]: time="2026-10-01T08:24:19Z" level=warning msg="dynamiclistener [::]:6443: no cached certificate available for preload - deferring certificate load until storage initialization or first client request" machine # [ 18.540259] k3s[847]: time="2026-10-01T08:24:19Z" 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__cd94_bd92_39cc_862c-7f4d6c:fec0::cd94:bd92:39cc:862c 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=89ADBC365F7C696A4F41EE4F6D1FA736AAAE7F93]" machine # [ 19.788807] k3s[847]: time="2026-10-01T08:24:20Z" level=info msg="Password verified locally for node machine" machine # [ 19.791252] k3s[847]: time="2026-10-01T08:24:20Z" level=info msg="certificate CN=machine signed by CN=k3s-server-ca@1790843059: notBefore=2026-10-01 07:24:20 +0000 UTC notAfter=2027-10-01 07:24:20 +0000 UTC" machine # [ 20.162838] k3s[847]: time="2026-10-01T08:24:20Z" level=info msg="certificate CN=system:node:machine,O=system:nodes signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:20 +0000 UTC notAfter=2027-10-01 07:24:20 +0000 UTC" machine # [ 20.291478] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:21 +0000 UTC notAfter=2027-10-01 07:24:21 +0000 UTC" machine # [ 20.440194] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1790843059: notBefore=2026-10-01 07:24:21 +0000 UTC notAfter=2027-10-01 07:24:21 +0000 UTC" machine # [ 20.584648] k3s[847]: time="2026-10-01T08:24:21Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:51158: runtime core not ready" machine # [ 20.721769] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Module overlay was already loaded" machine # [ 20.742814] rustfs-setup-start[882]: mb s3://niks3 machine # [ 20.753330] systemd[1]: Finished rustfs-setup.service. machine # [ 20.788685] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. machine # [ 20.795033] Bridge firewalling registered machine # [ 20.800989] k3s[847]: time="2026-10-01T08:24:21Z" level=warning msg="Failed to load kernel module iptable_nat with modprobe" machine # [ 20.809154] k3s[847]: time="2026-10-01T08:24:21Z" level=warning msg="Failed to load kernel module iptable_filter with modprobe" machine # [ 20.818153] k3s[847]: time="2026-10-01T08:24:21Z" level=warning msg="Failed to load kernel module nft-expr-counter with modprobe" machine # [ 20.866001] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 131072" machine # [ 20.867686] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400" machine # [ 20.869651] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600" machine # [ 20.871457] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Set sysctl 'net/ipv4/conf/all/forwarding' to 1" machine # [ 20.873081] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Creating k3s-cert-monitor event broadcaster" machine # [ 20.874601] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect" machine # [ 20.876332] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Saving cluster bootstrap data to datastore" machine # [ 20.879274] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]" machine # [ 20.882360] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Handling backend connection request [machine]" machine # [ 20.883705] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Connection to etcd is ready" machine # [ 20.885187] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="ETCD server is now running" machine # [ 20.886523] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Polling for API server readiness: GET /readyz failed: the server is currently unable to handle the request" machine # [ 20.888721] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect" machine # [ 20.890341] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect" machine # [ 20.892198] k3s[847]: time="2026-10-01T08:24:21Z" 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" machine # [ 20.927713] k3s[847]: time="2026-10-01T08:24:21Z" 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" machine # [ 20.936189] k3s[847]: time="2026-10-01T08:24:21Z" 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" machine # [ 20.965816] k3s[847]: time="2026-10-01T08:24:21Z" 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" machine # [ 20.974666] k3s[847]: I1001 08:24:21.706008 847 options.go:263] external host was not specified, using 10.0.2.15 machine # [ 20.976447] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Server node token is available at /var/lib/rancher/k3s/server/token" machine # [ 20.978189] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="To join server node to cluster: k3s server -s https://10.0.2.15:6443 -t ${SERVER_NODE_TOKEN}" machine # [ 20.980304] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Agent node token is available at /var/lib/rancher/k3s/server/agent-token" machine # [ 20.982068] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="To join agent node to cluster: k3s agent -s https://10.0.2.15:6443 -t ${AGENT_NODE_TOKEN}" machine # [ 20.984115] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml" machine # [ 20.985549] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Run: k3s kubectl" machine # [ 20.986710] k3s[847]: I1001 08:24:21.711745 847 server.go:158] Version: v1.36.4+k3s1 machine # [ 20.987996] k3s[847]: I1001 08:24:21.711779 847 server.go:160] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK="" machine # [ 21.052046] k3s[847]: time="2026-10-01T08:24:21Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:48210: runtime core not ready" machine # [ 21.080080] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log" machine # [ 21.091501] k3s[847]: time="2026-10-01T08:24:21Z" level=info msg="Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml" machine # [ 21.257358] k3s[847]: time="2026-10-01T08:24:22Z" 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" machine # [ 21.275596] k3s[847]: E1001 08:24:22.092446 847 options.go:205] The manifest file is empty, ignoring. machine # [ 21.278506] k3s[847]: I1001 08:24:22.094278 847 shared_informer.go:381] "Waiting for caches to sync" controller="node_authorizer" machine # [ 21.282518] k3s[847]: I1001 08:24:22.098908 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 21.283877] k3s[847]: I1001 08:24:22.099747 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 21.289000] k3s[847]: I1001 08:24:22.105931 847 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. machine # [ 21.294148] k3s[847]: I1001 08:24:22.109078 847 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. machine # [ 21.299823] k3s[847]: I1001 08:24:22.109602 847 instance.go:240] Using reconciler: lease machine # [ 21.304399] k3s[847]: I1001 08:24:22.121341 847 handler.go:304] Adding GroupVersion apiextensions.k8s.io v1 to ResourceManager machine # [ 21.305954] k3s[847]: W1001 08:24:22.121375 847 genericapiserver.go:798] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources. machine # [ 21.308752] k3s[847]: I1001 08:24:22.125459 847 cidrallocator.go:198] starting ServiceCIDR Allocator Controller machine # [ 21.384104] k3s[847]: I1001 08:24:22.200690 847 handler.go:304] Adding GroupVersion v1 to ResourceManager machine # [ 21.385648] k3s[847]: I1001 08:24:22.202038 847 apis.go:112] API group "internal.apiserver.k8s.io" is not enabled, skipping. machine # [ 21.433208] k3s[847]: I1001 08:24:22.250061 847 apis.go:112] API group "storagemigration.k8s.io" is not enabled, skipping. machine # [ 21.501788] k3s[847]: I1001 08:24:22.318429 847 handler.go:304] Adding GroupVersion authentication.k8s.io v1 to ResourceManager machine # [ 21.503516] k3s[847]: W1001 08:24:22.318481 847 genericapiserver.go:798] Skipping API authentication.k8s.io/v1beta1 because it has no resources. machine # [ 21.505420] k3s[847]: W1001 08:24:22.318493 847 genericapiserver.go:798] Skipping API authentication.k8s.io/v1alpha1 because it has no resources. machine # [ 21.507223] k3s[847]: I1001 08:24:22.322685 847 handler.go:304] Adding GroupVersion authorization.k8s.io v1 to ResourceManager machine # [ 21.508859] k3s[847]: W1001 08:24:22.322715 847 genericapiserver.go:798] Skipping API authorization.k8s.io/v1beta1 because it has no resources. machine # [ 21.510617] k3s[847]: I1001 08:24:22.323552 847 handler.go:304] Adding GroupVersion autoscaling v2 to ResourceManager machine # [ 21.512113] k3s[847]: I1001 08:24:22.324233 847 handler.go:304] Adding GroupVersion autoscaling v1 to ResourceManager machine # [ 21.513544] k3s[847]: I1001 08:24:22.325599 847 handler.go:304] Adding GroupVersion batch v1 to ResourceManager machine # [ 21.514905] k3s[847]: W1001 08:24:22.325616 847 genericapiserver.go:798] Skipping API batch/v1beta1 because it has no resources. machine # [ 21.516486] k3s[847]: I1001 08:24:22.326502 847 handler.go:304] Adding GroupVersion certificates.k8s.io v1 to ResourceManager machine # [ 21.517996] k3s[847]: W1001 08:24:22.326518 847 genericapiserver.go:798] Skipping API certificates.k8s.io/v1beta1 because it has no resources. machine # [ 21.519755] k3s[847]: W1001 08:24:22.326525 847 genericapiserver.go:798] Skipping API certificates.k8s.io/v1alpha1 because it has no resources. machine # [ 21.521557] k3s[847]: I1001 08:24:22.327065 847 handler.go:304] Adding GroupVersion coordination.k8s.io v1 to ResourceManager machine # [ 21.523059] k3s[847]: W1001 08:24:22.327075 847 genericapiserver.go:798] Skipping API coordination.k8s.io/v1beta1 because it has no resources. machine # [ 21.524784] k3s[847]: W1001 08:24:22.327081 847 genericapiserver.go:798] Skipping API coordination.k8s.io/v1alpha2 because it has no resources. machine # [ 21.526468] k3s[847]: I1001 08:24:22.327613 847 handler.go:304] Adding GroupVersion discovery.k8s.io v1 to ResourceManager machine # [ 21.527931] k3s[847]: W1001 08:24:22.327625 847 genericapiserver.go:798] Skipping API discovery.k8s.io/v1beta1 because it has no resources. machine # [ 21.529738] k3s[847]: I1001 08:24:22.330027 847 handler.go:304] Adding GroupVersion networking.k8s.io v1 to ResourceManager machine # [ 21.533179] k3s[847]: W1001 08:24:22.330050 847 genericapiserver.go:798] Skipping API networking.k8s.io/v1beta1 because it has no resources. machine # [ 21.534983] k3s[847]: I1001 08:24:22.330530 847 handler.go:304] Adding GroupVersion node.k8s.io v1 to ResourceManager machine # [ 21.536558] k3s[847]: W1001 08:24:22.330541 847 genericapiserver.go:798] Skipping API node.k8s.io/v1beta1 because it has no resources. machine # [ 21.538271] k3s[847]: W1001 08:24:22.330547 847 genericapiserver.go:798] Skipping API node.k8s.io/v1alpha1 because it has no resources. machine # [ 21.539984] k3s[847]: I1001 08:24:22.331318 847 handler.go:304] Adding GroupVersion policy v1 to ResourceManager machine # [ 21.541669] k3s[847]: W1001 08:24:22.331331 847 genericapiserver.go:798] Skipping API policy/v1beta1 because it has no resources. machine # [ 21.543374] k3s[847]: I1001 08:24:22.333193 847 handler.go:304] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager machine # [ 21.545053] k3s[847]: W1001 08:24:22.333213 847 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources. machine # [ 21.546817] k3s[847]: W1001 08:24:22.333220 847 genericapiserver.go:798] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources. machine # [ 21.548600] k3s[847]: I1001 08:24:22.333696 847 handler.go:304] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager machine # [ 21.550124] k3s[847]: W1001 08:24:22.333710 847 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1beta1 because it has no resources. machine # [ 21.551767] k3s[847]: W1001 08:24:22.333716 847 genericapiserver.go:798] Skipping API scheduling.k8s.io/v1alpha2 because it has no resources. machine # [ 21.553562] k3s[847]: I1001 08:24:22.336221 847 handler.go:304] Adding GroupVersion storage.k8s.io v1 to ResourceManager machine # [ 21.555013] k3s[847]: W1001 08:24:22.336245 847 genericapiserver.go:798] Skipping API storage.k8s.io/v1beta1 because it has no resources. machine # [ 21.556680] k3s[847]: W1001 08:24:22.336252 847 genericapiserver.go:798] Skipping API storage.k8s.io/v1alpha1 because it has no resources. machine # [ 21.558357] k3s[847]: I1001 08:24:22.337400 847 handler.go:304] Adding GroupVersion flowcontrol.apiserver.k8s.io v1 to ResourceManager machine # [ 21.563693] k3s[847]: W1001 08:24:22.337419 847 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta3 because it has no resources. machine # [ 21.565711] k3s[847]: W1001 08:24:22.337426 847 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta2 because it has no resources. machine # [ 21.567507] k3s[847]: W1001 08:24:22.337431 847 genericapiserver.go:798] Skipping API flowcontrol.apiserver.k8s.io/v1beta1 because it has no resources. machine # [ 21.572119] k3s[847]: I1001 08:24:22.340954 847 handler.go:304] Adding GroupVersion apps v1 to ResourceManager machine # [ 21.573572] k3s[847]: W1001 08:24:22.340978 847 genericapiserver.go:798] Skipping API apps/v1beta2 because it has no resources. machine # [ 21.575104] k3s[847]: W1001 08:24:22.340984 847 genericapiserver.go:798] Skipping API apps/v1beta1 because it has no resources. machine # [ 21.579526] k3s[847]: I1001 08:24:22.343645 847 handler.go:304] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager machine # [ 21.581369] k3s[847]: W1001 08:24:22.343668 847 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources. machine # [ 21.583199] k3s[847]: W1001 08:24:22.343677 847 genericapiserver.go:798] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources. machine # [ 21.588167] k3s[847]: I1001 08:24:22.344175 847 handler.go:304] Adding GroupVersion events.k8s.io v1 to ResourceManager machine # [ 21.589772] k3s[847]: W1001 08:24:22.344185 847 genericapiserver.go:798] Skipping API events.k8s.io/v1beta1 because it has no resources. machine # [ 21.591420] k3s[847]: I1001 08:24:22.346027 847 handler.go:304] Adding GroupVersion resource.k8s.io v1 to ResourceManager machine # [ 21.595288] k3s[847]: W1001 08:24:22.346048 847 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta2 because it has no resources. machine # [ 21.597170] k3s[847]: W1001 08:24:22.346054 847 genericapiserver.go:798] Skipping API resource.k8s.io/v1beta1 because it has no resources. machine # [ 21.598831] k3s[847]: W1001 08:24:22.346060 847 genericapiserver.go:798] Skipping API resource.k8s.io/v1alpha3 because it has no resources. machine # [ 21.600594] k3s[847]: I1001 08:24:22.349060 847 handler.go:304] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager machine # [ 21.602296] k3s[847]: W1001 08:24:22.349083 847 genericapiserver.go:798] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources. machine # [ 22.160564] k3s[847]: time="2026-10-01T08:24:22Z" level=info msg="containerd is now running" machine # [ 22.173406] k3s[847]: time="2026-10-01T08:24:22Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/a5wjhxz9hz2qbdaks6cr50fmi761fivl-niks3-server.tar" machine # [ 22.219916] k3s[847]: I1001 08:24:23.035761 847 secure_serving.go:214] Serving securely on 127.0.0.1:6444 machine # [ 22.221520] k3s[847]: I1001 08:24:23.035999 847 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt" machine # [ 22.223566] k3s[847]: I1001 08:24:23.036108 847 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" machine # [ 22.232151] k3s[847]: I1001 08:24:23.036182 847 tlsconfig.go:243] "Starting DynamicServingCertificateController" machine # [ 22.233679] k3s[847]: I1001 08:24:23.038743 847 local_available_controller.go:156] Starting LocalAvailability controller machine # [ 22.235124] k3s[847]: I1001 08:24:23.038759 847 cache.go:32] Waiting for caches to sync for LocalAvailability controller machine # [ 22.236645] k3s[847]: I1001 08:24:23.038792 847 controller.go:87] "Starting OpenAPI AggregationController" machine # [ 22.240119] k3s[847]: I1001 08:24:23.038826 847 controller.go:89] "Starting OpenAPI V3 AggregationController" machine # [ 22.241541] k3s[847]: I1001 08:24:23.039555 847 cluster_authentication_trust_controller.go:459] Starting cluster_authentication_trust_controller controller machine # [ 22.243397] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Waiting for caches to sync" logger=k3s machine # [ 22.248117] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Starting apiserver lease garbage collector" logger=k3s machine # [ 22.249701] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Waiting for caches to sync" logger=k3s machine # [ 22.250943] k3s[847]: I1001 08:24:23.039894 847 customresource_discovery_controller.go:294] Starting DiscoveryController machine # [ 22.252436] k3s[847]: I1001 08:24:23.039923 847 controller.go:113] "Deleting old lease on startup" lease="kube-system/apiserver-ik4pcwfs7qgdl76byc4pomgvia" machine # [ 22.254291] k3s[847]: I1001 08:24:23.040284 847 remote_available_controller.go:434] Starting RemoteAvailability controller machine # [ 22.255778] k3s[847]: I1001 08:24:23.040295 847 cache.go:32] Waiting for caches to sync for RemoteAvailability controller machine # [ 22.260113] k3s[847]: I1001 08:24:23.040325 847 aggregator.go:185] waiting for initial CRD sync... machine # [ 22.261373] k3s[847]: I1001 08:24:23.040343 847 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" machine # [ 22.267560] k3s[847]: I1001 08:24:23.040661 847 apiservice_controller.go:100] Starting APIServiceRegistrationController machine # [ 22.269227] k3s[847]: I1001 08:24:23.040671 847 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller machine # [ 22.271719] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Starting legacy_token_tracking_controller" logger=k3s machine # [ 22.273190] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Waiting for caches to sync" logger=k3s machine # [ 22.274407] k3s[847]: I1001 08:24:23.040875 847 system_namespaces_controller.go:66] Starting system namespaces controller machine # [ 22.275874] k3s[847]: I1001 08:24:23.041178 847 storage_readiness_hook.go:70] Storage is ready for all registered resources machine # [ 22.277558] k3s[847]: I1001 08:24:23.041611 847 apf_controller.go:377] Starting API Priority and Fairness config controller machine # [ 22.279043] k3s[847]: I1001 08:24:23.041668 847 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt" machine # [ 22.281159] k3s[847]: I1001 08:24:23.047675 847 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt" machine # [ 22.283144] k3s[847]: I1001 08:24:23.047781 847 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt" machine # [ 22.285410] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg=Starting controller=kubernetes-service-cidr-controller logger=k3s machine # [ 22.286933] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Waiting for caches to sync" logger=k3s machine # [ 22.288234] k3s[847]: I1001 08:24:23.048315 847 controller.go:142] Starting OpenAPI controller machine # [ 22.289434] k3s[847]: I1001 08:24:23.048347 847 controller.go:90] Starting OpenAPI V3 controller machine # [ 22.290651] k3s[847]: I1001 08:24:23.048365 847 naming_controller.go:305] Starting NamingConditionController machine # [ 22.292003] k3s[847]: I1001 08:24:23.048415 847 nonstructuralschema_controller.go:202] Starting NonStructuralSchemaConditionController machine # [ 22.293694] k3s[847]: I1001 08:24:23.048431 847 apiapproval_controller.go:196] Starting KubernetesAPIApprovalPolicyConformantConditionController machine # [ 22.295405] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Starting CRDFinalizer" logger=k3s machine # [ 22.296645] k3s[847]: I1001 08:24:23.048490 847 crdregistration_controller.go:114] Starting crd-autoregister controller machine # [ 22.298102] k3s[847]: I1001 08:24:23.048502 847 shared_informer.go:381] "Waiting for caches to sync" controller="crd-autoregister" machine # [ 22.299657] k3s[847]: I1001 08:24:23.049170 847 repairip.go:210] Starting ipallocator-repair-controller machine # [ 22.301061] k3s[847]: I1001 08:24:23.049187 847 shared_informer.go:381] "Waiting for caches to sync" controller="ipallocator-repair-controller" machine # [ 22.378708] k3s[847]: I1001 08:24:23.194999 847 shared_informer.go:388] "Caches are synced" controller="node_authorizer" machine # [ 22.382762] k3s[847]: I1001 08:24:23.199719 847 shared_informer.go:409] "Caches are synced" machine # [ 22.384004] k3s[847]: I1001 08:24:23.199771 847 policy_source.go:248] refreshing policies machine # [ 22.385242] k3s[847]: I1001 08:24:23.199857 847 shared_informer.go:409] "Caches are synced" machine # [ 22.386426] k3s[847]: I1001 08:24:23.199867 847 policy_source.go:248] refreshing policies machine # [ 22.413819] k3s[847]: E1001 08:24:23.230690 847 controller.go:201] "Failed to ensure lease exists, will retry" err="namespaces \"kube-system\" not found" interval="200ms" machine # [ 22.422206] k3s[847]: I1001 08:24:23.239133 847 cache.go:39] Caches are synced for LocalAvailability controller machine # [ 22.425116] k3s[847]: I1001 08:24:23.240825 847 cache.go:39] Caches are synced for APIServiceRegistrationController controller machine # [ 22.426744] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Caches are synced" logger=k3s machine # [ 22.427956] k3s[847]: I1001 08:24:23.240918 847 cache.go:39] Caches are synced for RemoteAvailability controller machine # [ 22.433967] k3s[847]: I1001 08:24:23.240966 847 handler_discovery.go:459] Starting ResourceDiscoveryManager machine # [ 22.435420] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Caches are synced" logger=k3s machine # [ 22.437753] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Caches are synced" logger=k3s machine # [ 22.438982] k3s[847]: I1001 08:24:23.241713 847 apf_controller.go:382] Running API Priority and Fairness config worker machine # [ 22.442494] k3s[847]: I1001 08:24:23.241730 847 apf_controller.go:385] Running API Priority and Fairness periodic rebalancing process machine # [ 22.446775] k3s[847]: I1001 08:24:23.250221 847 shared_informer.go:388] "Caches are synced" controller="ipallocator-repair-controller" machine # [ 22.448590] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Caches are synced" logger=k3s machine # [ 22.449767] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Creating default ServiceCIDR" CIDRs="[10.43.0.0/16]" logger=k3s machine # [ 22.451262] k3s[847]: I1001 08:24:23.251391 847 shared_informer.go:388] "Caches are synced" controller="crd-autoregister" machine # [ 22.456143] k3s[847]: I1001 08:24:23.252068 847 aggregator.go:187] initial CRD sync complete... machine # [ 22.458521] k3s[847]: I1001 08:24:23.252095 847 autoregister_controller.go:144] Starting autoregister controller machine # [ 22.459983] k3s[847]: I1001 08:24:23.252105 847 cache.go:32] Waiting for caches to sync for autoregister controller machine # [ 22.463151] k3s[847]: I1001 08:24:23.252114 847 cache.go:39] Caches are synced for autoregister controller machine # [ 22.465527] k3s[847]: I1001 08:24:23.263620 847 cidrallocator.go:302] created ClusterIP allocator for Service CIDR 10.43.0.0/16 machine # [ 22.467131] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Setting default ServiceCIDR condition Ready to True" logger=k3s machine # [ 22.472158] k3s[847]: I1001 08:24:23.282703 847 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/16 machine # [ 22.502885] k3s[847]: I1001 08:24:23.319803 847 alloc.go:329] "allocated clusterIPs" service="default/kubernetes" clusterIPs={"IPv4":"10.43.0.1"} machine # [ 22.520071] k3s[847]: W1001 08:24:23.335905 847 lease.go:265] Resetting endpoints for master service "kubernetes" to [10.0.2.15] machine # [ 22.521753] k3s[847]: I1001 08:24:23.337369 847 controller.go:667] quota admission added evaluator for: endpoints machine # [ 22.523674] k3s[847]: I1001 08:24:23.340562 847 controller.go:667] quota admission added evaluator for: endpointslices.discovery.k8s.io machine # [ 22.555685] k3s[847]: E1001 08:24:23.372512 847 controller.go:102] Error removing old endpoints from kubernetes service: no API server IP addresses were listed in storage, refusing to erase all endpoints for the kubernetes Service machine # [ 22.626850] k3s[847]: I1001 08:24:23.442465 847 controller.go:667] quota admission added evaluator for: leases.coordination.k8s.io machine # [ 22.874304] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Polling for API server readiness: GET /readyz failed: unknown" machine # [ 22.899457] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Imported docker.io/library/niks3-server:1.4.0-aarch64-linux" machine # [ 22.901662] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Tagged docker.io/library/niks3-server@sha256:6f65edb4eab69661a295599ae8c6b2e86a120f7e8ebeab81f0f984c8c57e5923" machine # [ 22.939572] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Imported 1 images from /var/lib/rancher/k3s/agent/images/nixos/a5wjhxz9hz2qbdaks6cr50fmi761fivl-niks3-server.tar in 766.29288ms" machine # [ 22.942555] k3s[847]: time="2026-10-01T08:24:23Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/nixos/lf2s5pc8i15d9jlqqva8rkqqip46lm3k-k3s-airgap-images-arm64.tar.zst" machine # [ 23.180606] k3s[847]: time="2026-10-01T08:24:23Z" 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::cd94:bd92:39cc:862c --node-labels= --read-only-port=0" machine # [ 23.230642] k3s[847]: I1001 08:24:24.047234 847 storage_scheduling.go:137] created PriorityClass system-node-critical with value 2000001000 machine # [ 23.233532] k3s[847]: I1001 08:24:24.050484 847 storage_scheduling.go:137] created PriorityClass system-cluster-critical with value 2000000000 machine # [ 23.235285] k3s[847]: I1001 08:24:24.050509 847 storage_scheduling.go:153] all system priority classes are created successfully or already exist. machine # [ 24.014294] k3s[847]: I1001 08:24:24.831187 847 controller.go:667] quota admission added evaluator for: roles.rbac.authorization.k8s.io machine # [ 24.049958] k3s[847]: I1001 08:24:24.866866 847 controller.go:667] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io machine # [ 24.878742] k3s[847]: 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. machine # [ 24.888982] k3s[847]: time="2026-10-01T08:24:25Z" level=info msg="Creating k3s-supervisor event broadcaster" machine # [ 24.890580] k3s[847]: time="2026-10-01T08:24:25Z" level=info msg="Waiting for untainted node" machine # [ 24.893723] k3s[847]: time="2026-10-01T08:24:25Z" level=info msg="Kube API server is now running" machine # [ 24.895163] k3s[847]: time="2026-10-01T08:24:25Z" level=info msg="k3s is up and running" machine # [ 24.896841] systemd[1]: Started k3s service. machine # [ 24.897550] systemd[1]: Reached target Multi-User System. machine # [ 24.898337] systemd[1]: Startup finished in 763ms (kernel) + 3.896s (initrd) + 20.235s (userspace) = 24.895s. machine # [ 24.908327] k3s[847]: time="2026-10-01T08:24:25Z" 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=Normal machine # [ 24.913274] k3s[847]: I1001 08:24:25.729597 847 server.go:541] "Kubelet version" kubeletVersion="v1.36.4+k3s1" machine # [ 24.915268] k3s[847]: I1001 08:24:25.729629 847 server.go:543] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK="" machine # [ 24.917187] k3s[847]: I1001 08:24:25.729679 847 watchdog_linux.go:94] "Systemd watchdog is not enabled" machine # [ 24.920203] k3s[847]: I1001 08:24:25.729689 847 watchdog_linux.go:137] "Systemd watchdog is not enabled or the interval is invalid, so health checking will not be started." machine # [ 24.922331] k3s[847]: I1001 08:24:25.738180 847 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt" machine # [ 24.940769] k3s[847]: E1001 08:24:25.757705 847 options.go:205] The manifest file is empty, ignoring. machine # [ 24.944065] k3s[847]: I1001 08:24:25.760448 847 controllermanager.go:204] "Starting" version="v1.36.4+k3s1" machine # [ 24.945530] k3s[847]: I1001 08:24:25.760490 847 controllermanager.go:206] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK="" machine # [ 24.947132] k3s[847]: I1001 08:24:25.763643 847 server.go:1444] "Using cgroup driver setting received from the CRI runtime" cgroupDriver="systemd" machine # [ 24.950978] k3s[847]: I1001 08:24:25.767891 847 server.go:804] "--cgroups-per-qos enabled, but --cgroup-root was not specified. Defaulting to /" machine # [ 24.953936] k3s[847]: I1001 08:24:25.767944 847 server.go:865] "NoSwap is set due to memorySwapBehavior not specified" memorySwapBehavior="" FailSwapOn=false machine # [ 24.956436] k3s[847]: I1001 08:24:25.770368 847 container_manager_linux.go:273] "Container manager verified user specified cgroup-root exists" cgroupRoot=[] machine # [ 24.958667] k3s[847]: I1001 08:24:25.770422 847 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} machine # [ 24.975936] k3s[847]: I1001 08:24:25.770697 847 topology_manager.go:172] "Creating topology manager with none policy" machine # [ 24.977919] k3s[847]: I1001 08:24:25.770715 847 container_manager_linux.go:309] "Creating device plugin manager" machine # [ 24.980377] k3s[847]: I1001 08:24:25.772957 847 container_manager_linux.go:318] "Creating Dynamic Resource Allocation (DRA) manager" machine # [ 24.984245] k3s[847]: I1001 08:24:25.798337 847 secure_serving.go:214] Serving securely on 127.0.0.1:10257 machine # [ 24.987230] k3s[847]: I1001 08:24:25.799061 847 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController machine # [ 24.993987] k3s[847]: I1001 08:24:25.799083 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 24.995308] k3s[847]: I1001 08:24:25.799118 847 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" machine # [ 25.000730] k3s[847]: I1001 08:24:25.799400 847 state_mem.go:45] "Initialized" logger="CPUManager state memory" machine # [ 25.002125] k3s[847]: I1001 08:24:25.799698 847 kubelet.go:485] "Attempting to sync node with API server" machine # [ 25.003424] k3s[847]: I1001 08:24:25.799717 847 kubelet.go:386] "Adding static pod path" path="/var/lib/rancher/k3s/agent/pod-manifests" machine # [ 25.005412] k3s[847]: I1001 08:24:25.799743 847 kubelet.go:397] "Adding apiserver pod source" machine # [ 25.010654] k3s[847]: I1001 08:24:25.799761 847 apiserver.go:41] "Waiting for node sync before watching apiserver pods" machine # [ 25.013486] k3s[847]: I1001 08:24:25.799915 847 tlsconfig.go:243] "Starting DynamicServingCertificateController" machine # [ 25.016151] k3s[847]: I1001 08:24:25.799997 847 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file" machine # [ 25.018594] k3s[847]: I1001 08:24:25.800028 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 25.021674] k3s[847]: I1001 08:24:25.800045 847 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file" machine # [ 25.024350] k3s[847]: I1001 08:24:25.800059 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 25.026373] k3s[847]: I1001 08:24:25.812882 847 kuberuntime_manager.go:308] "Container runtime initialized" containerRuntime="containerd" version="2.3.4-k3s1.36" apiVersion="v1" machine # [ 25.030138] k3s[847]: I1001 08:24:25.813928 847 kubelet.go:1002] "Not starting ClusterTrustBundle informer because we are in static kubelet mode or the ClusterTrustBundleProjection featuregate is disabled" machine # [ 25.034452] k3s[847]: I1001 08:24:25.814038 847 kubelet.go:1029] "Not starting PodCertificateRequest manager because we are in static kubelet mode or the PodCertificateProjection feature gate is disabled" machine # [ 25.039306] k3s[847]: W1001 08:24:25.814130 847 probe.go:275] Flexvolume plugin directory at /usr/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating. machine # [ 25.042579] k3s[847]: I1001 08:24:25.857778 847 server.go:1280] "Started kubelet" machine # [ 25.044202] k3s[847]: I1001 08:24:25.859494 847 server.go:193] "Starting to listen" address="0.0.0.0" port=10250 machine # [ 25.048947] k3s[847]: I1001 08:24:25.865849 847 ratelimit.go:56] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=10 machine # [ 25.050757] k3s[847]: I1001 08:24:25.866000 847 server_v1.go:49] "podresources" method="list" useActivePods=true machine # [ 25.056044] k3s[847]: I1001 08:24:25.866273 847 server.go:264] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock" machine # [ 25.059365] k3s[847]: I1001 08:24:25.868107 847 fs_resource_analyzer.go:69] "Starting FS ResourceAnalyzer" machine # [ 25.061023] k3s[847]: I1001 08:24:25.872260 847 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" machine # [ 25.069226] k3s[847]: I1001 08:24:25.872420 847 tlsconfig.go:243] "Starting DynamicServingCertificateController" machine # [ 25.070690] k3s[847]: I1001 08:24:25.873868 847 server.go:354] "Adding debug handlers to kubelet server" machine # [ 25.072096] k3s[847]: I1001 08:24:25.885172 847 volume_manager.go:310] "Starting Kubelet Volume Manager" machine # [ 25.073438] k3s[847]: E1001 08:24:25.885490 847 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found" machine # [ 25.075312] k3s[847]: E1001 08:24:25.885757 847 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine" machine # [ 25.078351] k3s[847]: I1001 08:24:25.888600 847 desired_state_of_world_populator.go:146] "Desired state populator starts to run" machine # [ 25.079853] k3s[847]: I1001 08:24:25.888689 847 reconciler.go:29] "Reconciler: start to sync state" machine: (finished: waiting for unit k3s.service, in 25.79 seconds) machine # [ 25.090751] k3s[847]: I1001 08:24:25.907668 847 factory.go:222] Registration of the containerd container factory successfully machine: waiting for unit rustfs-setup.service machine # [ 25.092377] k3s[847]: I1001 08:24:25.907711 847 factory.go:222] Registration of the systemd container factory successfully machine # [ 25.093869] k3s[847]: I1001 08:24:25.907877 847 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 directory machine # [ 25.096512] k3s[847]: E1001 08:24:25.913177 847 kubelet.go:1725] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem" machine: (finished: waiting for unit rustfs-setup.service, in 0.03 seconds) machine: waiting for unit postgresql.service machine # [ 25.134431] k3s[847]: time="2026-10-01T08:24:25Z" level=info msg="Creating embedded CRD addons.k3s.cattle.io" machine # [ 25.151040] k3s[847]: I1001 08:24:25.967576 847 controller.go:667] quota admission added evaluator for: serviceaccounts machine # [ 25.170513] k3s[847]: E1001 08:24:25.987395 847 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine" machine: (finished: waiting for unit postgresql.service, in 0.06 seconds) subtest: chart deploys and becomes ready ??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/iiab4a2pmymr5lc22a6yc0d0fyf3g00n-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 machine: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s ??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/iiab4a2pmymr5lc22a6yc0d0fyf3g00n-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 machine # [ 25.192191] k3s[847]: E1001 08:24:26.009124 847 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found" machine # [ 25.212650] k3s[847]: I1001 08:24:26.026987 847 shared_informer.go:409] "Caches are synced" machine # [ 25.214013] k3s[847]: I1001 08:24:26.027214 847 shared_informer.go:409] "Caches are synced" machine # [ 25.215291] k3s[847]: I1001 08:24:26.027251 847 shared_informer.go:409] "Caches are synced" machine # [ 25.216707] k3s[847]: E1001 08:24:26.027495 847 nodelease.go:50] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"machine\" not found" node="machine" machine # [ 25.218946] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Creating embedded CRD etcdsnapshotfiles.k3s.cattle.io" machine # [ 25.244601] k3s[847]: I1001 08:24:26.061553 847 cpu_manager.go:235] "Starting" policy="none" machine # [ 25.248297] k3s[847]: I1001 08:24:26.065251 847 cpu_manager.go:236] "Reconciling" reconcilePeriod="10s" machine # [ 25.252104] k3s[847]: I1001 08:24:26.066736 847 state_mem.go:45] "Initialized" logger="CPUManager state checkpoint.CPUManager state memory" machine # [ 25.253904] k3s[847]: I1001 08:24:26.063828 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 25.261501] k3s[847]: I1001 08:24:26.078392 847 policy_none.go:50] "Start" machine # [ 25.262591] k3s[847]: I1001 08:24:26.078427 847 memory_manager.go:190] "Starting memorymanager" policy="None" machine # [ 25.263933] k3s[847]: I1001 08:24:26.078448 847 state_mem.go:40] "Initializing new in-memory state store" logger="Memory Manager state checkpoint" machine # [ 25.269755] k3s[847]: I1001 08:24:26.084577 847 policy_none.go:44] "Start" machine # [ 25.270853] k3s[847]: E1001 08:24:26.085832 847 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine" machine # [ 25.298007] k3s[847]: E1001 08:24:26.114952 847 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found" machine # [ 25.302695] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Creating embedded CRD helmchartconfigs.helm.cattle.io" machine # [ 25.331955] systemd[1]: Created slice libcontainer container kubepods.slice. machine # [ 25.412175] k3s[847]: E1001 08:24:26.221437 847 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine" machine # [ 25.414530] k3s[847]: E1001 08:24:26.221577 847 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found" machine # [ 25.419070] k3s[847]: I1001 08:24:26.225605 847 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv4" machine # [ 25.424376] k3s[847]: I1001 08:24:26.229301 847 kubelet_network_linux.go:53] "Initialized iptables rules." protocol="IPv6" machine # [ 25.425970] k3s[847]: I1001 08:24:26.229341 847 status_manager.go:277] "Starting to sync pod status with apiserver" machine # [ 25.427382] k3s[847]: I1001 08:24:26.229387 847 kubelet.go:2622] "Starting kubelet main sync loop" machine # [ 25.432152] k3s[847]: E1001 08:24:26.229462 847 kubelet.go:2646] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]" machine # [ 25.462350] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Creating embedded CRD helmcharts.helm.cattle.io" machine # [ 25.463862] k3s[847]: I1001 08:24:26.277622 847 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager machine # [ 25.470390] k3s[847]: E1001 08:24:26.287209 847 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine" machine # [ 25.483590] systemd[1]: Created slice libcontainer container kubepods-burstable.slice. machine # [ 25.507332] k3s[847]: E1001 08:24:26.324259 847 kubelet_node_status.go:396] "Error getting the current node from lister" err="node \"machine\" not found" machine # [ 25.512242] systemd[1]: Created slice libcontainer container kubepods-besteffort.slice. machine # [ 25.519919] k3s[847]: E1001 08:24:26.336865 847 kubelet.go:2646] "Skipping pod synchronization" err="container runtime status check may not have completed yet" machine # [ 25.551117] k3s[847]: I1001 08:24:26.368054 847 shared_informer.go:409] "Caches are synced" machine # [ 25.564349] k3s[847]: E1001 08:24:26.381245 847 manager.go:525] "Failed to read data from checkpoint" err="checkpoint is not found" checkpoint="kubelet_internal_checkpoint" machine # [ 25.567840] k3s[847]: I1001 08:24:26.382910 847 eviction_manager.go:194] "Eviction manager: starting control loop" machine # [ 25.570527] k3s[847]: I1001 08:24:26.382973 847 container_log_manager.go:146] "Initializing container log rotate workers" workers=1 monitorPeriod="10s" machine # [ 25.575364] k3s[847]: I1001 08:24:26.390368 847 plugin_manager.go:121] "Starting Kubelet Plugin Manager" machine # [ 25.577061] k3s[847]: E1001 08:24:26.392847 847 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine" machine # [ 25.581437] k3s[847]: I1001 08:24:26.395701 847 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager machine # [ 25.600429] k3s[847]: E1001 08:24:26.417305 847 eviction_manager.go:272] "eviction manager: failed to check if we have separate container filesystem. Ignoring." err="no imagefs label for configured runtime" machine # [ 25.605485] k3s[847]: E1001 08:24:26.417378 847 eviction_manager.go:297] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"machine\" not found" machine # [ 25.611753] k3s[847]: E1001 08:24:26.428684 847 csi_plugin.go:403] Failed to initialize CSINode: error updating CSINode annotation: timed out waiting for the condition; caused by: nodes "machine" not found machine # [ 25.640300] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Waiting for CRD helmcharts.helm.cattle.io to become available" machine # [ 25.643648] k3s[847]: I1001 08:24:26.460616 847 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 25.669229] k3s[847]: E1001 08:24:26.486092 847 kubelet.go:3516] "Unable to register mirror pod because node is not registered yet" err="node \"machine\" not found" node="machine" machine # [ 25.671419] k3s[847]: I1001 08:24:26.487058 847 kubelet_node_status.go:75] "Attempting to register node" node="machine" machine # [ 25.687802] k3s[847]: I1001 08:24:26.502856 847 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager machine # [ 25.695202] k3s[847]: I1001 08:24:26.512132 847 kubelet_node_status.go:78] "Successfully registered node" node="machine" machine # [ 25.716645] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Annotations and labels have been set successfully on node: machine" machine # [ 25.721745] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Starting flannel with backend vxlan" machine # [ 25.744242] k3s[847]: I1001 08:24:26.559829 847 kubelet_node_status.go:431] "Fast updating node status as it just became ready" machine # [ 25.995779] k3s[847]: I1001 08:24:26.809645 847 apiserver.go:51] "Watching apiserver" machine # [ 26.170281] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Done waiting for CRD helmcharts.helm.cattle.io to become available" machine # [ 26.172137] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-40.1.4+up40.1.0.tgz" machine # [ 26.174058] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-40.1.4+up40.1.0.tgz" machine # [ 26.175911] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml" machine # [ 26.177927] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml" machine # [ 26.179628] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml" machine # [ 26.181443] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml" machine # [ 26.183142] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/runtimes.yaml" machine # [ 26.184783] k3s[847]: time="2026-10-01T08:24:26Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml" machine # [ 26.418065] k3s[847]: I1001 08:24:27.234909 847 range_allocator.go:113] "No Secondary Service CIDR provided. Skipping filtering out secondary service addresses" logger="node-ipam-controller" machine # [ 26.424233] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Starting dynamiclistener CN filter node controller with SANs: [127.0.0.1 ::1 localhost machine 10.0.2.15 fec0::cd94:bd92:39cc:862c 10.43.0.1 kubernetes kubernetes.default kubernetes.default.svc kubernetes.default.svc.cluster.local]" machine # [ 26.427706] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tunnel server egress proxy mode: agent" machine # [ 26.438943] k3s[847]: I1001 08:24:27.255881 847 controllermanager.go:641] "Warning: skipping controller" controller="storage-version-migrator-controller" machine # [ 26.471873] k3s[847]: I1001 08:24:27.288788 847 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world" machine # [ 26.503896] k3s[847]: I1001 08:24:27.320750 847 controllermanager.go:689] "Warning: controller is disabled" controller="node-route-controller" machine # [ 26.524080] k3s[847]: time="2026-10-01T08:24:27Z" 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__cd94_bd92_39cc_862c-7f4d6c:fec0::cd94:bd92:39cc:862c 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=89ADBC365F7C696A4F41EE4F6D1FA736AAAE7F93]" machine # [ 26.538323] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Active TLS secret kube-system/k3s-serving (ver=254) (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__cd94_bd92_39cc_862c-7f4d6c:fec0::cd94:bd92:39cc:862c 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=89ADBC365F7C696A4F41EE4F6D1FA736AAAE7F93]" machine # [ 26.557701] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/klipper-helm:v0.13.3-build20260727" machine # [ 26.559688] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/klipper-helm@sha256:5425a2b4613d2458dbdff99218e8d487ebb59c20e7a941f061c0777070f0aac1" machine # [ 26.563293] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/klipper-lb:v0.4.17" machine # [ 26.564820] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/klipper-lb@sha256:910944bb0bd94f060a82a56ca1ea1c577d3e49b3473a093a47a985f32e92d94a" machine # [ 26.567281] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.37" machine # [ 26.569084] k3s[847]: I1001 08:24:27.380790 847 server.go:228] "Successfully retrieved NodeIPs" NodeIPs=["10.0.2.15","fec0::cd94:bd92:39cc:862c"] machine # [ 26.571069] k3s[847]: E1001 08:24:27.381663 847 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`" machine # [ 26.574401] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/local-path-provisioner@sha256:e757967a5ec338f6a9b371c5a9688bedaa8c3578ea3dd4db329ea0084be0a86f" machine # [ 26.577133] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/mirrored-coredns-coredns:1.14.6" machine # [ 26.578833] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/mirrored-coredns-coredns@sha256:900f9c109f7a33545d3c811516e8376df9019147b750f5ce3e254468769176ea" machine # [ 26.582349] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/mirrored-library-busybox:1.37.0" machine # [ 26.584897] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/mirrored-library-busybox@sha256:101b4afd76732482eff9b95cae5f94bcf295e521fbec4e01b69c5421f3f3f3e5" machine # [ 26.588302] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/mirrored-library-traefik:3.7.8" machine # [ 26.592378] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/mirrored-library-traefik@sha256:4299bbed850421258fc5448c2e0e6ad350981d4d335a68de11b92448aedbefe5" machine # [ 26.594997] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/mirrored-metrics-server:v0.9.0" machine # [ 26.596869] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/mirrored-metrics-server@sha256:d9862115e7c7881280d3d75ca26bda8ffc0fc213315979575bf23ce9826205c0" machine # [ 26.599932] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported docker.io/rancher/mirrored-pause:3.10.2" machine # [ 26.602474] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Tagged docker.io/rancher/mirrored-pause@sha256:f548e0e8e3dc1896ca956272154dde3314e8cc4fde0a57577ee9fa1c63f5baf4" machine # [ 26.630370] k3s[847]: I1001 08:24:27.447251 847 server.go:274] "kube-proxy running in dual-stack mode" primary ipFamily="IPv4" machine # [ 26.632877] k3s[847]: I1001 08:24:27.449142 847 server_linux.go:137] "Using iptables Proxier" machine # [ 26.658519] k3s[847]: I1001 08:24:27.475406 847 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" machine # [ 26.678021] k3s[847]: I1001 08:24:27.494693 847 server.go:539] "Version info" version="v1.36.4+k3s1" machine # [ 26.680841] k3s[847]: I1001 08:24:27.494745 847 server.go:541] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK="" machine # [ 26.684035] k3s[847]: I1001 08:24:27.500374 847 config.go:200] "Starting service config controller" machine # [ 26.688271] k3s[847]: I1001 08:24:27.500451 847 shared_informer.go:381] "Waiting for caches to sync" controller="service config" machine # [ 26.689958] k3s[847]: I1001 08:24:27.500497 847 config.go:106] "Starting endpoint slice config controller" machine # [ 26.691280] k3s[847]: I1001 08:24:27.500516 847 shared_informer.go:381] "Waiting for caches to sync" controller="endpoint slice config" machine # [ 26.696074] k3s[847]: I1001 08:24:27.500560 847 config.go:403] "Starting serviceCIDR config controller" machine # [ 26.698846] k3s[847]: I1001 08:24:27.502837 847 shared_informer.go:381] "Waiting for caches to sync" controller="serviceCIDR config" machine # [ 26.701777] k3s[847]: I1001 08:24:27.500886 847 config.go:309] "Starting node config controller" machine # [ 26.704340] k3s[847]: I1001 08:24:27.502874 847 shared_informer.go:381] "Waiting for caches to sync" controller="node config" machine # [ 26.706873] k3s[847]: I1001 08:24:27.502882 847 shared_informer.go:388] "Caches are synced" controller="node config" machine # [ 26.783887] k3s[847]: I1001 08:24:27.600803 847 shared_informer.go:388] "Caches are synced" controller="service config" machine # [ 26.788241] k3s[847]: I1001 08:24:27.602961 847 shared_informer.go:388] "Caches are synced" controller="endpoint slice config" machine # [ 26.789939] k3s[847]: I1001 08:24:27.603163 847 shared_informer.go:388] "Caches are synced" controller="serviceCIDR config" machine # [ 26.883881] k3s[847]: time="2026-10-01T08:24:27Z" level=info msg="Imported 8 images from /var/lib/rancher/k3s/agent/images/nixos/lf2s5pc8i15d9jlqqva8rkqqip46lm3k-k3s-airgap-images-arm64.tar.zst in 3.94394332s" machine # [ 26.929042] k3s[847]: I1001 08:24:27.745766 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmchartconfigs.helm.cattle.io" machine # [ 26.933598] k3s[847]: I1001 08:24:27.745882 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="addons.k3s.cattle.io" machine # [ 26.936226] k3s[847]: I1001 08:24:27.746199 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpoints" machine # [ 26.938574] k3s[847]: I1001 08:24:27.746251 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="resourceclaimtemplates.resource.k8s.io" machine # [ 26.941398] k3s[847]: I1001 08:24:27.748928 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="horizontalpodautoscalers.autoscaling" machine # [ 26.943911] k3s[847]: I1001 08:24:27.748996 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="cronjobs.batch" machine # [ 26.946404] k3s[847]: I1001 08:24:27.749072 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="serviceaccounts" machine # [ 26.948799] k3s[847]: I1001 08:24:27.749105 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="deployments.apps" machine # [ 26.951257] k3s[847]: I1001 08:24:27.749133 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpointslices.discovery.k8s.io" machine # [ 26.954007] k3s[847]: I1001 08:24:27.749176 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmcharts.helm.cattle.io" machine # [ 26.956404] k3s[847]: I1001 08:24:27.749256 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="leases.coordination.k8s.io" machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 26.958766] k3s[847]: I1001 08:24:27.749332 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="replicasets.apps" machine # [ 26.961797] k3s[847]: I1001 08:24:27.749412 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="rolebindings.rbac.authorization.k8s.io" machine # [ 26.964235] k3s[847]: I1001 08:24:27.749470 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="limitranges" machine # [ 26.966491] k3s[847]: I1001 08:24:27.749540 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="controllerrevisions.apps" machine # [ 26.968833] k3s[847]: I1001 08:24:27.749627 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="daemonsets.apps" machine # [ 26.971051] k3s[847]: I1001 08:24:27.749739 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="networkpolicies.networking.k8s.io" machine # [ 26.974792] k3s[847]: I1001 08:24:27.749784 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="podtemplates" machine # [ 26.977138] k3s[847]: I1001 08:24:27.749828 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="poddisruptionbudgets.policy" machine # [ 26.980516] k3s[847]: I1001 08:24:27.749893 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="csistoragecapacities.storage.k8s.io" machine # [ 26.983064] k3s[847]: I1001 08:24:27.750022 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="roles.rbac.authorization.k8s.io" machine # [ 26.985760] k3s[847]: I1001 08:24:27.750102 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="statefulsets.apps" machine # [ 26.988275] k3s[847]: I1001 08:24:27.750132 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="jobs.batch" machine # [ 26.990554] k3s[847]: I1001 08:24:27.750161 847 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="ingresses.networking.k8s.io" machine # [ 26.993061] k3s[847]: I1001 08:24:27.790066 847 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podcertificaterequest-cleaner-controller" requiredFeatureGates=["PodCertificateRequest"] machine # [ 26.996199] k3s[847]: I1001 08:24:27.790147 847 controllermanager.go:641] "Warning: skipping controller" controller="podcertificaterequest-cleaner-controller" machine # [ 26.998229] k3s[847]: I1001 08:24:27.790157 847 controllermanager.go:689] "Warning: controller is disabled" controller="cloud-node-lifecycle-controller" machine # [ 27.124352] k3s[847]: I1001 08:24:27.941225 847 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller" requiredFeatureGates=["ClusterTrustBundle"] machine # [ 27.127464] k3s[847]: I1001 08:24:27.941269 847 controllermanager.go:641] "Warning: skipping controller" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller" machine # [ 27.733267] k3s[847]: time="2026-10-01T08:24:28Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller" machine # [ 27.733575] k3s[847]: time="2026-10-01T08:24:28Z" level=info msg="Creating deploy event broadcaster" machine # [ 27.747750] k3s[847]: I1001 08:24:28.564502 847 controller.go:667] quota admission added evaluator for: addons.k3s.cattle.io machine # [ 27.756314] k3s[847]: time="2026-10-01T08:24:28Z" level=info msg="Creating helm-controller event broadcaster" machine # [ 27.758680] k3s[847]: time="2026-10-01T08:24:28Z" level=info msg="Starting /v1, Kind=Node controller" machine # [ 27.782318] k3s[847]: time="2026-10-01T08:24:28Z" 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=Normal machine # [ 27.798044] k3s[847]: time="2026-10-01T08:24:28Z" level=info msg="Labels and annotations have been set successfully on node: machine" machine # [ 27.804250] k3s[847]: time="2026-10-01T08:24:28Z" level=info msg="Cluster dns configmap has been set successfully" machine # [ 27.925714] k3s[847]: I1001 08:24:28.742607 847 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="storageversion-garbage-collector-controller" requiredFeatureGates=["APIServerIdentity","StorageVersionAPI"] machine # [ 27.932233] k3s[847]: I1001 08:24:28.747286 847 controllermanager.go:641] "Warning: skipping controller" controller="storageversion-garbage-collector-controller" machine # [ 28.082872] k3s[847]: I1001 08:24:28.898151 847 controllermanager.go:689] "Warning: controller is disabled" controller="bootstrap-signer-controller" machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 28.226844] k3s[847]: I1001 08:24:29.043764 847 controllermanager.go:689] "Warning: controller is disabled" controller="selinux-warning-controller" machine # [ 28.235029] k3s[847]: time="2026-10-01T08:24:29Z" 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=Normal machine # [ 28.250492] k3s[847]: time="2026-10-01T08:24:29Z" 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=Normal machine # [ 28.376757] k3s[847]: I1001 08:24:29.193564 847 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podgroup-protection-controller" requiredFeatureGates=["GenericWorkload"] machine # [ 28.382365] k3s[847]: I1001 08:24:29.197638 847 controllermanager.go:641] "Warning: skipping controller" controller="podgroup-protection-controller" machine # [ 28.462142] k3s[847]: time="2026-10-01T08:24:29Z" 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=Normal machine # [ 28.481526] k3s[847]: time="2026-10-01T08:24:29Z" 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=Normal machine # [ 28.892149] k3s[847]: time="2026-10-01T08:24:29Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller" machine # [ 28.903320] k3s[847]: time="2026-10-01T08:24:29Z" level=info msg="Starting batch/v1, Kind=Job controller" machine # [ 28.908306] k3s[847]: time="2026-10-01T08:24:29Z" level=info msg="Starting /v1, Kind=ServiceAccount controller" machine # [ 28.912185] k3s[847]: time="2026-10-01T08:24:29Z" level=info msg="Starting /v1, Kind=Secret controller" machine # [ 28.914303] k3s[847]: time="2026-10-01T08:24:29Z" level=info msg="Starting /v1, Kind=ConfigMap controller" machine # [ 28.927284] k3s[847]: time="2026-10-01T08:24:29Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller" machine # [ 28.930091] k3s[847]: time="2026-10-01T08:24:29Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller" machine # [ 29.061201] k3s[847]: I1001 08:24:29.878089 847 serving.go:417] Generated self-signed cert in-memory machine # [ 29.136721] k3s[847]: I1001 08:24:29.950165 847 controller.go:667] quota admission added evaluator for: deployments.apps machine # [ 29.152914] k3s[847]: I1001 08:24:29.969739 847 serving.go:417] Generated self-signed cert in-memory machine # [ 29.307229] k3s[847]: I1001 08:24:30.122818 847 alloc.go:329] "allocated clusterIPs" service="kube-system/kube-dns" clusterIPs={"IPv4":"10.43.0.10"} machine # [ 29.325333] k3s[847]: time="2026-10-01T08:24:30Z" 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=Normal machine # [ 29.493523] k3s[847]: I1001 08:24:30.310435 847 controllermanager.go:163] Version: v1.36.4+k3s1 machine # [ 29.499118] k3s[847]: I1001 08:24:30.316066 847 secure_serving.go:214] Serving securely on 127.0.0.1:10258 machine # [ 29.501338] k3s[847]: I1001 08:24:30.317139 847 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController machine # [ 29.507201] k3s[847]: I1001 08:24:30.317798 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 29.508767] k3s[847]: I1001 08:24:30.317162 847 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file" machine # [ 29.511932] k3s[847]: I1001 08:24:30.317868 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 29.516102] k3s[847]: I1001 08:24:30.317181 847 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file" machine # [ 29.523963] k3s[847]: I1001 08:24:30.317885 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 29.525472] k3s[847]: I1001 08:24:30.317210 847 tlsconfig.go:243] "Starting DynamicServingCertificateController" machine # [ 29.526856] k3s[847]: time="2026-10-01T08:24:30Z" level=info msg="Creating service-lb-controller event broadcaster" machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 29.601178] k3s[847]: I1001 08:24:30.418054 847 shared_informer.go:409] "Caches are synced" machine # [ 29.603196] k3s[847]: I1001 08:24:30.418089 847 shared_informer.go:409] "Caches are synced" machine # [ 29.605281] k3s[847]: I1001 08:24:30.418150 847 shared_informer.go:409] "Caches are synced" machine # [ 29.625775] k3s[847]: I1001 08:24:30.442668 847 controllermanager.go:689] "Warning: controller is disabled" controller="service-lb-controller" machine # [ 29.632271] k3s[847]: I1001 08:24:30.445649 847 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="resourcepoolstatusrequest-controller" requiredFeatureGates=["DRAResourcePoolStatus"] machine # [ 29.637396] k3s[847]: I1001 08:24:30.445696 847 controllermanager.go:641] "Warning: skipping controller" controller="resourcepoolstatusrequest-controller" machine # [ 29.860737] k3s[847]: time="2026-10-01T08:24:30Z" level=info msg="Starting /v1, Kind=Node controller" machine # [ 29.879480] k3s[847]: time="2026-10-01T08:24:30Z" level=info msg="Starting /v1, Kind=Pod controller" machine # [ 29.886764] k3s[847]: time="2026-10-01T08:24:30Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller" machine # [ 29.910293] k3s[847]: I1001 08:24:30.725596 847 controllermanager.go:338] Started "cloud-node-controller" machine # [ 29.911706] k3s[847]: I1001 08:24:30.725893 847 controllermanager.go:338] Started "cloud-node-lifecycle-controller" machine # [ 29.913262] k3s[847]: I1001 08:24:30.726526 847 controllermanager.go:338] Started "service-lb-controller" machine # [ 29.914591] k3s[847]: W1001 08:24:30.726538 847 controllermanager.go:315] "node-route-controller" is disabled machine # [ 29.915953] k3s[847]: time="2026-10-01T08:24:30Z" level=info msg="Starting discovery.k8s.io/v1, Kind=EndpointSlice controller" machine # [ 29.920162] k3s[847]: I1001 08:24:30.727540 847 node_controller.go:179] Sending events to api server. machine # [ 29.921509] k3s[847]: I1001 08:24:30.727617 847 node_lifecycle_controller.go:112] Sending events to api server machine # [ 29.922885] k3s[847]: I1001 08:24:30.727754 847 node_controller.go:188] Waiting for informer caches to sync machine # [ 29.928200] k3s[847]: I1001 08:24:30.727861 847 controller.go:235] Starting service controller machine # [ 29.929418] k3s[847]: I1001 08:24:30.727882 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 29.990838] k3s[847]: time="2026-10-01T08:24:30Z" level=info msg="Event occurred" apiVersion= fieldPath= kind=Node logger=k3s message="Deferred node password secret validation complete" object=machine reason=NodePasswordValidationComplete type=Normal machine # [ 30.126613] k3s[847]: time="2026-10-01T08:24:30Z" 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=Normal machine # [ 30.140822] k3s[847]: time="2026-10-01T08:24:30Z" 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=Normal machine # [ 30.173859] k3s[847]: I1001 08:24:30.990693 847 node_lifecycle_controller.go:402] "Controller will reconcile labels" logger="node-lifecycle-controller" machine # [ 30.184192] k3s[847]: I1001 08:24:30.996628 847 node_lifecycle_controller.go:436] "Sending events to api server" machine # [ 30.186477] k3s[847]: I1001 08:24:30.998181 847 clusterroleaggregation_controller.go:176] "Starting ClusterRoleAggregator controller" machine # [ 30.189162] k3s[847]: I1001 08:24:30.998230 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.191094] k3s[847]: I1001 08:24:30.998300 847 servicecidrs_controller.go:137] "Starting" controller="service-cidr-controller" machine # [ 30.200328] k3s[847]: I1001 08:24:30.998333 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.202353] k3s[847]: I1001 08:24:30.998402 847 endpointslicemirroring_controller.go:226] "Starting EndpointSliceMirroring controller" machine # [ 30.205046] k3s[847]: I1001 08:24:30.998416 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.207024] k3s[847]: I1001 08:24:30.998667 847 certificate_controller.go:120] "Starting certificate controller" name="csrapproving" machine # [ 30.212186] k3s[847]: I1001 08:24:30.998684 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.214087] k3s[847]: I1001 08:24:30.998770 847 attach_detach_controller.go:334] "Starting attach detach controller" machine # [ 30.220157] k3s[847]: I1001 08:24:30.998787 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.221976] k3s[847]: I1001 08:24:30.998845 847 endpoints_controller.go:193] "Starting endpoint controller" machine # [ 30.223686] k3s[847]: I1001 08:24:30.998865 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.225408] k3s[847]: I1001 08:24:30.998932 847 endpointslice_controller.go:280] "Starting endpoint slice controller" machine # [ 30.227206] k3s[847]: I1001 08:24:30.998946 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.232145] k3s[847]: I1001 08:24:30.998989 847 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-legacy-unknown" machine # [ 30.234295] k3s[847]: I1001 08:24:30.999004 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.235790] k3s[847]: I1001 08:24:30.999032 847 tokencleaner.go:117] "Starting token cleaner controller" machine # [ 30.239618] k3s[847]: I1001 08:24:30.999047 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.241256] k3s[847]: I1001 08:24:30.999105 847 pv_controller_base.go:318] "Starting persistent volume controller" machine # [ 30.242873] k3s[847]: I1001 08:24:30.999120 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.248325] k3s[847]: I1001 08:24:30.999145 847 controller.go:174] "Starting ephemeral volume controller" machine # [ 30.250565] k3s[847]: I1001 08:24:30.999158 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.251917] k3s[847]: I1001 08:24:30.999220 847 device_taint_eviction.go:783] "Starting" controller="device-taint-eviction-controller" numWorkers=8 machine # [ 30.256180] k3s[847]: I1001 08:24:30.999374 847 pvc_protection_controller.go:172] "Starting PVC protection controller" machine # [ 30.257822] k3s[847]: I1001 08:24:30.999423 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.259164] k3s[847]: I1001 08:24:30.999482 847 daemon_controller.go:364] "Starting daemon sets controller" machine # [ 30.264196] k3s[847]: I1001 08:24:30.999497 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.265630] k3s[847]: I1001 08:24:30.999524 847 pv_protection_controller.go:81] "Starting PV protection controller" machine # [ 30.267128] k3s[847]: I1001 08:24:30.999536 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.268519] k3s[847]: I1001 08:24:30.999559 847 ttlafterfinished_controller.go:112] "Starting TTL after finished controller" machine # [ 30.270184] k3s[847]: I1001 08:24:30.999572 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.271518] k3s[847]: I1001 08:24:30.999597 847 publisher.go:107] "Starting root CA cert publisher controller" machine # [ 30.275069] k3s[847]: I1001 08:24:30.999614 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.276485] k3s[847]: I1001 08:24:30.999642 847 legacy_serviceaccount_token_cleaner.go:103] "Starting legacy service account token cleaner controller" machine # [ 30.278473] k3s[847]: I1001 08:24:30.999656 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.279812] k3s[847]: I1001 08:24:30.999675 847 serviceaccounts_controller.go:117] "Starting service account controller" machine # [ 30.284172] k3s[847]: I1001 08:24:30.999688 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.285637] k3s[847]: I1001 08:24:30.999764 847 job_controller.go:336] "Starting job controller" machine # [ 30.286917] k3s[847]: I1001 08:24:30.999783 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.292309] k3s[847]: I1001 08:24:30.999812 847 horizontal.go:204] "Starting HPA controller" machine # [ 30.293545] k3s[847]: I1001 08:24:30.999823 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.294794] k3s[847]: I1001 08:24:30.999857 847 ttl_controller.go:127] "Starting TTL controller" machine # [ 30.295979] k3s[847]: I1001 08:24:30.999874 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.300237] k3s[847]: I1001 08:24:30.999897 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.301547] k3s[847]: I1001 08:24:30.999926 847 gc_controller.go:98] "Starting GC controller" machine # [ 30.302729] k3s[847]: I1001 08:24:30.999943 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.303969] k3s[847]: I1001 08:24:30.999995 847 stateful_set.go:234] "Starting stateful set controller" machine # [ 30.308116] k3s[847]: I1001 08:24:31.000008 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.309506] k3s[847]: I1001 08:24:31.000046 847 node_lifecycle_controller.go:443] "Starting node controller" machine # [ 30.310838] k3s[847]: I1001 08:24:31.000056 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.312105] k3s[847]: I1001 08:24:31.000174 847 resource_quota_controller.go:297] "Starting resource quota controller" machine # [ 30.313563] k3s[847]: I1001 08:24:31.000191 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.314808] k3s[847]: I1001 08:24:31.000226 847 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-serving" machine # [ 30.320119] k3s[847]: I1001 08:24:31.000240 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.321426] k3s[847]: I1001 08:24:31.000260 847 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-client" machine # [ 30.323167] k3s[847]: I1001 08:24:31.000274 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.328228] k3s[847]: I1001 08:24:31.000296 847 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kube-apiserver-client" machine # [ 30.330157] k3s[847]: I1001 08:24:31.000321 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.331407] k3s[847]: I1001 08:24:31.000358 847 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" machine # [ 30.334223] k3s[847]: I1001 08:24:31.000556 847 device_taint_eviction.go:823] "Sending events to api server" machine # [ 30.335574] k3s[847]: I1001 08:24:31.000662 847 device_taint_eviction.go:1023] "Waiting" for="cache and event handler sync" machine # [ 30.340224] k3s[847]: I1001 08:24:31.000754 847 resource_quota_monitor.go:309] "QuotaMonitor running" machine # [ 30.341580] k3s[847]: I1001 08:24:31.000949 847 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" machine # [ 30.348155] k3s[847]: I1001 08:24:31.001106 847 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" machine # [ 30.350839] k3s[847]: I1001 08:24:31.001192 847 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" machine # [ 30.353537] k3s[847]: I1001 08:24:31.003328 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.354763] k3s[847]: I1001 08:24:31.003398 847 vac_protection_controller.go:206] "Starting VAC protection controller" machine # [ 30.360157] k3s[847]: I1001 08:24:31.003417 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.361467] k3s[847]: I1001 08:24:31.003442 847 taint_eviction.go:283] "Starting" controller="taint-eviction-controller" machine # [ 30.362927] k3s[847]: I1001 08:24:31.003492 847 taint_eviction.go:288] "Sending events to API server" machine # [ 30.364219] k3s[847]: I1001 08:24:31.003504 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.365536] k3s[847]: I1001 08:24:31.003564 847 replica_set.go:285] "Starting controller" name="replicationcontroller" machine # [ 30.366971] k3s[847]: I1001 08:24:31.003578 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.368245] k3s[847]: I1001 08:24:31.003605 847 disruption.go:453] "Sending events to api server." machine # [ 30.369465] k3s[847]: I1001 08:24:31.003641 847 disruption.go:460] "Starting disruption controller" machine # [ 30.370686] k3s[847]: I1001 08:24:31.003651 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.371926] k3s[847]: I1001 08:24:31.003689 847 cleaner.go:83] "Starting CSR cleaner controller" machine # [ 30.373210] k3s[847]: I1001 08:24:31.003808 847 node_ipam_controller.go:142] "Starting ipam controller" machine # [ 30.374485] k3s[847]: I1001 08:24:31.003824 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.375728] k3s[847]: I1001 08:24:31.003846 847 expand_controller.go:328] "Starting expand controller" machine # [ 30.377083] k3s[847]: I1001 08:24:31.003860 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.378328] k3s[847]: I1001 08:24:31.003921 847 controller.go:753] "Starting resource claim controller" machine # [ 30.379599] k3s[847]: I1001 08:24:31.003937 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.380904] k3s[847]: I1001 08:24:31.003958 847 namespace_controller.go:202] "Starting namespace controller" machine # [ 30.382218] k3s[847]: I1001 08:24:31.003973 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.383419] k3s[847]: I1001 08:24:31.004151 847 deployment_controller.go:180] "Starting controller" controller="deployment" machine # [ 30.384931] k3s[847]: I1001 08:24:31.004167 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.386131] k3s[847]: I1001 08:24:31.004261 847 cronjob_controllerv2.go:143] "Starting cronjob controller v2" machine # [ 30.387423] k3s[847]: I1001 08:24:31.004275 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.388682] k3s[847]: I1001 08:24:31.004693 847 garbagecollector.go:141] "Starting controller" controller="garbagecollector" machine # [ 30.390196] k3s[847]: I1001 08:24:31.004715 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.391404] k3s[847]: I1001 08:24:31.004757 847 replica_set.go:285] "Starting controller" name="replicaset" machine # [ 30.392753] k3s[847]: I1001 08:24:31.004771 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.394006] k3s[847]: I1001 08:24:31.004979 847 graph_builder.go:387] "Running" component="GraphBuilder" machine # [ 30.395283] k3s[847]: I1001 08:24:31.015809 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.396579] k3s[847]: I1001 08:24:31.027919 847 node_controller.go:432] Initializing node machine with cloud provider machine # [ 30.398063] k3s[847]: I1001 08:24:31.028224 847 shared_informer.go:409] "Caches are synced" machine # [ 30.399197] k3s[847]: time="2026-10-01T08:24:31Z" level=info msg="Adding node OwnerReference to node-password secret machine.node-password.k3s" machine # [ 30.400915] k3s[847]: I1001 08:24:31.073955 847 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" machine # [ 30.404250] k3s[847]: I1001 08:24:31.084962 847 controller.go:667] quota admission added evaluator for: helmcharts.helm.cattle.io machine # [ 30.405792] k3s[847]: I1001 08:24:31.091535 847 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceClaim" machine # [ 30.407844] k3s[847]: time="2026-10-01T08:24:31Z" 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=Normal machine # [ 30.411277] k3s[847]: I1001 08:24:31.091737 847 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" machine # [ 30.414470] k3s[847]: E1001 08:24:31.094477 847 options.go:205] The manifest file is empty, ignoring. machine # [ 30.415725] k3s[847]: I1001 08:24:31.100154 847 shared_informer.go:409] "Caches are synced" machine # [ 30.417076] k3s[847]: I1001 08:24:31.105568 847 node_controller.go:477] Successfully initialized node machine with cloud provider machine # [ 30.418637] k3s[847]: I1001 08:24:31.105997 847 shared_informer.go:409] "Caches are synced" machine # [ 30.419791] k3s[847]: I1001 08:24:31.106049 847 range_allocator.go:177] "Sending events to api server" machine # [ 30.421179] k3s[847]: I1001 08:24:31.106076 847 range_allocator.go:181] "Starting range CIDR allocator" machine # [ 30.422453] k3s[847]: I1001 08:24:31.106083 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.423697] k3s[847]: I1001 08:24:31.106089 847 shared_informer.go:409] "Caches are synced" machine # [ 30.424923] k3s[847]: I1001 08:24:31.106401 847 shared_informer.go:409] "Caches are synced" machine # [ 30.426066] k3s[847]: I1001 08:24:31.106439 847 shared_informer.go:409] "Caches are synced" machine # [ 30.427207] k3s[847]: I1001 08:24:31.106554 847 event.go:389] "Event occurred" object="machine" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="Synced" message="Node synced successfully" machine # [ 30.429649] k3s[847]: I1001 08:24:31.122376 847 server.go:176] "Starting Kubernetes Scheduler" version="v1.36.4+k3s1" machine # [ 30.431067] k3s[847]: I1001 08:24:31.122404 847 server.go:178] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK="" machine # [ 30.432528] k3s[847]: I1001 08:24:31.124560 847 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.ResourceSlice" machine # [ 30.434576] k3s[847]: I1001 08:24:31.124709 847 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.DeviceClass" machine # [ 30.436651] k3s[847]: I1001 08:24:31.124736 847 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" machine # [ 30.439609] k3s[847]: time="2026-10-01T08:24:31Z" level=info msg="Synced coredns NodeHosts entries for machine" machine # [ 30.441006] k3s[847]: I1001 08:24:31.135926 847 range_allocator.go:433] "Set node PodCIDR" node="machine" podCIDRs=["10.42.0.0/24"] machine # [ 30.442563] k3s[847]: I1001 08:24:31.138504 847 secure_serving.go:214] Serving securely on 127.0.0.1:10259 machine # [ 30.444041] k3s[847]: I1001 08:24:31.138601 847 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController machine # [ 30.445573] k3s[847]: I1001 08:24:31.138618 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.446811] k3s[847]: I1001 08:24:31.138647 847 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" machine # [ 30.449838] k3s[847]: I1001 08:24:31.138743 847 tlsconfig.go:243] "Starting DynamicServingCertificateController" machine # [ 30.451207] k3s[847]: I1001 08:24:31.140602 847 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file" machine # [ 30.453639] k3s[847]: I1001 08:24:31.140625 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.455723] k3s[847]: I1001 08:24:31.140641 847 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file" machine # [ 30.458164] k3s[847]: I1001 08:24:31.140653 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.459404] k3s[847]: time="2026-10-01T08:24:31Z" 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=Normal machine # [ 30.463048] k3s[847]: I1001 08:24:31.176515 847 device_taint_eviction.go:1023] "Done waiting" for="cache and event handler sync" instance="SharedIndexInformer *v1.Pod" machine # [ 30.465028] k3s[847]: I1001 08:24:31.176659 847 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" machine # [ 30.467820] k3s[847]: I1001 08:24:31.183816 847 shared_informer.go:402] "Waiting for caches to sync" machine # [ 30.469172] k3s[847]: I1001 08:24:31.198380 847 shared_informer.go:409] "Caches are synced" machine # [ 30.470295] k3s[847]: I1001 08:24:31.198575 847 shared_informer.go:409] "Caches are synced" machine # [ 30.471403] k3s[847]: I1001 08:24:31.198744 847 shared_informer.go:409] "Caches are synced" machine # [ 30.472562] k3s[847]: I1001 08:24:31.198835 847 shared_informer.go:409] "Caches are synced" machine # [ 30.473699] k3s[847]: I1001 08:24:31.198910 847 shared_informer.go:409] "Caches are synced" machine # [ 30.474839] k3s[847]: I1001 08:24:31.198965 847 shared_informer.go:409] "Caches are synced" machine # [ 30.475984] k3s[847]: I1001 08:24:31.199037 847 shared_informer.go:409] "Caches are synced" machine # [ 30.477257] k3s[847]: I1001 08:24:31.199096 847 shared_informer.go:409] "Caches are synced" machine # [ 30.478404] k3s[847]: I1001 08:24:31.199149 847 shared_informer.go:409] "Caches are synced" machine # [ 30.479550] k3s[847]: I1001 08:24:31.199178 847 shared_informer.go:409] "Caches are synced" machine # [ 30.480753] k3s[847]: I1001 08:24:31.199484 847 shared_informer.go:409] "Caches are synced" machine # [ 30.481893] k3s[847]: I1001 08:24:31.199602 847 shared_informer.go:409] "Caches are synced" machine # [ 30.483035] k3s[847]: I1001 08:24:31.199637 847 shared_informer.go:409] "Caches are synced" machine # [ 30.484195] k3s[847]: I1001 08:24:31.199802 847 shared_informer.go:409] "Caches are synced" machine # [ 30.485375] k3s[847]: I1001 08:24:31.199883 847 shared_informer.go:409] "Caches are synced" machine # [ 30.486505] k3s[847]: I1001 08:24:31.199935 847 shared_informer.go:409] "Caches are synced" machine # [ 30.487650] k3s[847]: I1001 08:24:31.199963 847 shared_informer.go:409] "Caches are synced" machine # [ 30.488847] k3s[847]: I1001 08:24:31.200042 847 shared_informer.go:409] "Caches are synced" machine # [ 30.489984] k3s[847]: I1001 08:24:31.200075 847 shared_informer.go:409] "Caches are synced" machine # [ 30.491116] k3s[847]: I1001 08:24:31.200138 847 node_lifecycle_controller.go:1217] "Initializing eviction metric for zone" zone="" machine # [ 30.492716] k3s[847]: I1001 08:24:31.200208 847 node_lifecycle_controller.go:869] "Missing timestamp for Node. Assuming now as a timestamp" node="machine" machine # [ 30.494632] k3s[847]: I1001 08:24:31.200255 847 shared_informer.go:409] "Caches are synced" machine # [ 30.495781] k3s[847]: I1001 08:24:31.200279 847 shared_informer.go:409] "Caches are synced" machine # [ 30.496985] k3s[847]: I1001 08:24:31.200302 847 shared_informer.go:409] "Caches are synced" machine # [ 30.498114] k3s[847]: I1001 08:24:31.200343 847 shared_informer.go:409] "Caches are synced" machine # [ 30.499261] k3s[847]: I1001 08:24:31.204211 847 shared_informer.go:409] "Caches are synced" machine # [ 30.500447] k3s[847]: I1001 08:24:31.205163 847 shared_informer.go:409] "Caches are synced" machine # [ 30.501642] k3s[847]: I1001 08:24:31.206151 847 shared_informer.go:409] "Caches are synced" machine # [ 30.502775] k3s[847]: I1001 08:24:31.206183 847 shared_informer.go:409] "Caches are synced" machine # [ 30.503920] k3s[847]: I1001 08:24:31.206220 847 shared_informer.go:409] "Caches are synced" machine # [ 30.505147] k3s[847]: I1001 08:24:31.206324 847 shared_informer.go:409] "Caches are synced" machine # [ 30.506317] k3s[847]: I1001 08:24:31.207070 847 node_lifecycle_controller.go:1063] "Controller detected that zone is now in new state" zone="" newState="Normal" machine # [ 30.508232] k3s[847]: I1001 08:24:31.207276 847 shared_informer.go:409] "Caches are synced" machine # [ 30.509431] k3s[847]: I1001 08:24:31.207325 847 shared_informer.go:409] "Caches are synced" machine # [ 30.510564] k3s[847]: I1001 08:24:31.207362 847 shared_informer.go:409] "Caches are synced" machine # [ 30.511705] k3s[847]: I1001 08:24:31.207388 847 shared_informer.go:409] "Caches are synced" machine # [ 30.512904] k3s[847]: I1001 08:24:31.207410 847 shared_informer.go:409] "Caches are synced" machine # [ 30.514048] k3s[847]: I1001 08:24:31.207485 847 shared_informer.go:409] "Caches are synced" machine # [ 30.515182] k3s[847]: I1001 08:24:31.207988 847 shared_informer.go:409] "Caches are synced" machine # [ 30.516344] k3s[847]: I1001 08:24:31.217407 847 shared_informer.go:409] "Caches are synced" machine # [ 30.517548] k3s[847]: I1001 08:24:31.304320 847 shared_informer.go:409] "Caches are synced" machine # [ 30.522364] k3s[847]: I1001 08:24:31.339237 847 shared_informer.go:409] "Caches are synced" machine # [ 30.524728] k3s[847]: I1001 08:24:31.341665 847 shared_informer.go:409] "Caches are synced" machine # [ 30.525924] k3s[847]: I1001 08:24:31.341740 847 shared_informer.go:409] "Caches are synced" machine # [ 30.657003] k3s[847]: time="2026-10-01T08:24:31Z" 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=Normal machine # [ 30.667596] k3s[847]: time="2026-10-01T08:24:31Z" 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=Normal machine # [ 30.682433] k3s[847]: time="2026-10-01T08:24:31Z" 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=Normal machine # [ 30.696478] k3s[847]: I1001 08:24:31.513418 847 controller.go:667] quota admission added evaluator for: jobs.batch machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 30.830349] k3s[847]: I1001 08:24:31.647232 847 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/16 machine # [ 30.843534] k3s[847]: I1001 08:24:31.659963 847 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/16 machine # [ 30.853474] k3s[847]: time="2026-10-01T08:24:31Z" level=info msg="Flannel found PodCIDR assigned for node machine" machine # [ 30.869697] k3s[847]: time="2026-10-01T08:24:31Z" level=info msg="The interface eth0 with ipv4 address 10.0.2.15 will be used by flannel" machine # [ 30.871542] k3s[847]: I1001 08:24:31.687715 847 kube.go:139] Waiting 10m0s for node controller to sync machine # [ 30.873101] k3s[847]: I1001 08:24:31.688678 847 kube.go:537] Starting kube subnet manager machine # [ 30.888040] k3s[847]: time="2026-10-01T08:24:31Z" level=info msg="Tunnel authorizer set Kubelet Port 0.0.0.0:10250" machine # [ 30.896088] k3s[847]: time="2026-10-01T08:24:31Z" 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=Normal machine # [ 30.988159] k3s[847]: time="2026-10-01T08:24:31Z" 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=Normal machine # [ 31.228862] k3s[847]: I1001 08:24:32.045108 847 controller.go:667] quota admission added evaluator for: replicasets.apps machine # [ 31.299246] k3s[847]: time="2026-10-01T08:24:32Z" 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=Normal machine # [ 31.448136] k3s[847]: E1001 08:24:32.262987 847 replica_set.go:640] "Unhandled Error" err="sync \"kube-system/coredns-54996dc9b4\" failed with read version: 388 is not as new as written version: 394 for group resource replicasets.apps" logger="UnhandledError" machine # [ 31.459710] k3s[847]: E1001 08:24:32.275715 847 replica_set.go:640] "Unhandled Error" err="sync \"kube-system/coredns-54996dc9b4\" failed with read version: 388 is not as new as written version: 394 for group resource replicasets.apps" logger="UnhandledError" machine # [ 31.474218] k3s[847]: I1001 08:24:32.287570 847 shared_informer.go:409] "Caches are synced" machine # [ 31.486906] systemd[1]: Created slice libcontainer container kubepods-burstable-poda07fe4e0_c2ce_49c7_8dd3_54332a14401b.slice. machine # [ 31.493560] k3s[847]: I1001 08:24:32.310460 847 shared_informer.go:409] "Caches are synced" machine # [ 31.495334] k3s[847]: I1001 08:24:32.310506 847 garbagecollector.go:166] "Garbage collector: all resource monitors have synced" machine # [ 31.498491] k3s[847]: I1001 08:24:32.310514 847 garbagecollector.go:169] "Proceeding to collect garbage" machine # [ 31.529530] systemd[1]: Created slice libcontainer container kubepods-burstable-pod327b78eb_21e9_4a2a_a4f4_950998887667.slice. machine # [ 31.584444] k3s[847]: I1001 08:24:32.401255 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"custom-config-volume\" (UniqueName: \"kubernetes.io/configmap/a07fe4e0-c2ce-49c7-8dd3-54332a14401b-custom-config-volume\") pod \"coredns-54996dc9b4-xxg46\" (UID: \"a07fe4e0-c2ce-49c7-8dd3-54332a14401b\") " pod="kube-system/coredns-54996dc9b4-xxg46" machine # [ 31.591822] k3s[847]: I1001 08:24:32.401313 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-q2px6\" (UniqueName: \"kubernetes.io/projected/a07fe4e0-c2ce-49c7-8dd3-54332a14401b-kube-api-access-q2px6\") pod \"coredns-54996dc9b4-xxg46\" (UID: \"a07fe4e0-c2ce-49c7-8dd3-54332a14401b\") " pod="kube-system/coredns-54996dc9b4-xxg46" machine # [ 31.599151] k3s[847]: I1001 08:24:32.401344 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-helm\") pod \"helm-install-niks3-p2vd4\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " pod="kube-system/helm-install-niks3-p2vd4" machine # [ 31.606025] k3s[847]: I1001 08:24:32.401371 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-tmp\") pod \"helm-install-niks3-p2vd4\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " pod="kube-system/helm-install-niks3-p2vd4" machine # [ 31.612695] k3s[847]: I1001 08:24:32.401397 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-24kw7\" (UniqueName: \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-kube-api-access-24kw7\") pod \"helm-install-niks3-p2vd4\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " pod="kube-system/helm-install-niks3-p2vd4" machine # [ 31.619714] k3s[847]: I1001 08:24:32.401425 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"config-volume\" (UniqueName: \"kubernetes.io/configmap/a07fe4e0-c2ce-49c7-8dd3-54332a14401b-config-volume\") pod \"coredns-54996dc9b4-xxg46\" (UID: \"a07fe4e0-c2ce-49c7-8dd3-54332a14401b\") " pod="kube-system/coredns-54996dc9b4-xxg46" machine # [ 31.626232] k3s[847]: I1001 08:24:32.401449 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-cache\") pod \"helm-install-niks3-p2vd4\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " pod="kube-system/helm-install-niks3-p2vd4" machine # [ 31.632271] k3s[847]: I1001 08:24:32.401471 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-config\") pod \"helm-install-niks3-p2vd4\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " pod="kube-system/helm-install-niks3-p2vd4" machine # [ 31.637814] k3s[847]: I1001 08:24:32.401494 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"values\" (UniqueName: \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-values\") pod \"helm-install-niks3-p2vd4\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " pod="kube-system/helm-install-niks3-p2vd4" machine # [ 31.642899] k3s[847]: I1001 08:24:32.401529 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"content\" (UniqueName: \"kubernetes.io/configmap/327b78eb-21e9-4a2a-a4f4-950998887667-content\") pod \"helm-install-niks3-p2vd4\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " pod="kube-system/helm-install-niks3-p2vd4" machine # [ 31.871981] k3s[847]: I1001 08:24:32.688689 847 kube.go:163] Node controller sync successful machine # [ 31.875048] k3s[847]: I1001 08:24:32.688808 847 vxlan.go:128] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false machine # [ 31.879715] k3s[847]: I1001 08:24:32.692631 847 kube.go:704] List of node(machine) annotations: map[string]string{"alpha.kubernetes.io/provided-node-ip":"10.0.2.15,fec0::cd94:bd92:39cc:862c", "k3s.io/hostname":"machine", "k3s.io/internal-ip":"10.0.2.15,fec0::cd94:bd92:39cc:862c", "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"} machine # [ 31.942502] k3s[847]: I1001 08:24:32.759193 847 iptables.go:50] Starting flannel in iptables mode... machine # [ 31.943912] k3s[847]: time="2026-10-01T08:24:32Z" level=warning msg="no subnet found for key: FLANNEL_NETWORK in file: /run/flannel/subnet.env" machine # [ 31.948854] k3s[847]: time="2026-10-01T08:24:32Z" level=warning msg="no subnet found for key: FLANNEL_SUBNET in file: /run/flannel/subnet.env" machine # [ 31.952356] k3s[847]: time="2026-10-01T08:24:32Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_NETWORK in file: /run/flannel/subnet.env" machine # [ 31.954152] k3s[847]: time="2026-10-01T08:24:32Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_SUBNET in file: /run/flannel/subnet.env" machine # [ 31.955870] k3s[847]: I1001 08:24:32.759430 847 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 rules machine # [ 31.961362] k3s[847]: I1001 08:24:32.767658 847 kube.go:558] Creating the node lease for IPv4. This is the n.Spec.PodCIDRs: [10.42.0.0/24] machine # [ 32.010761] (udev-worker)[1242]: Network interface NamePolicy= disabled on kernel command line. machine # [ 32.050908] k3s[847]: E1001 08:24:32.865530 847 remote_runtime.go:237] "RunPodSandbox from runtime service failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"96067d8ac02c1213d2a8846fc54177dd8f0ca5723b7dacf44b478248f8fec0fe\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" machine # [ 32.057391] k3s[847]: E1001 08:24:32.867934 847 kuberuntime_sandbox.go:70] "Failed to create sandbox for pod" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"96067d8ac02c1213d2a8846fc54177dd8f0ca5723b7dacf44b478248f8fec0fe\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/coredns-54996dc9b4-xxg46" machine # [ 32.063611] k3s[847]: E1001 08:24:32.867966 847 kuberuntime_manager.go:1640] "CreatePodSandbox for pod failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"96067d8ac02c1213d2a8846fc54177dd8f0ca5723b7dacf44b478248f8fec0fe\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/coredns-54996dc9b4-xxg46" machine # [ 32.069120] k3s[847]: E1001 08:24:32.868070 847 pod_workers.go:1338] "Error syncing pod, skipping" err="failed to \"CreatePodSandbox\" for \"coredns-54996dc9b4-xxg46_kube-system(a07fe4e0-c2ce-49c7-8dd3-54332a14401b)\" with CreatePodSandboxError: \"Failed to create sandbox for pod \\\"coredns-54996dc9b4-xxg46_kube-system(a07fe4e0-c2ce-49c7-8dd3-54332a14401b)\\\": rpc error: code = Unknown desc = failed to setup network for sandbox \\\"96067d8ac02c1213d2a8846fc54177dd8f0ca5723b7dacf44b478248f8fec0fe\\\": plugin type=\\\"flannel\\\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory\"" pod="kube-system/coredns-54996dc9b4-xxg46" podUID="a07fe4e0-c2ce-49c7-8dd3-54332a14401b" machine # [ 32.081858] dhcpcd[619]: flannel.1: IAID 32:90:35:3c machine # [ 32.083294] dhcpcd[619]: flannel.1: adding address fe80::ac08:32ff:fe90:353c machine # [ 32.085209] k3s[847]: I1001 08:24:32.899948 847 iptables.go:111] Setting up masking rules machine # [ 32.096734] k3s[847]: I1001 08:24:32.913681 847 iptables.go:212] Changing default FORWARD chain policy to ACCEPT machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 32.119155] k3s[847]: time="2026-10-01T08:24:32Z" level=info msg="Wrote flannel subnet file to /run/flannel/subnet.env" machine # [ 32.121046] k3s[847]: time="2026-10-01T08:24:32Z" level=info msg="Running flannel backend" machine # [ 32.122536] k3s[847]: I1001 08:24:32.936046 847 vxlan_network.go:68] watching for new subnet leases machine # [ 32.124112] k3s[847]: I1001 08:24:32.937724 847 vxlan_network.go:115] starting vxlan device watcher machine # [ 32.171451] (udev-worker)[1240]: Network interface NamePolicy= disabled on kernel command line. machine # [ 32.191419] (udev-worker)[1243]: Network interface NamePolicy= disabled on kernel command line.[ 32.196008] cni0: port 1(veth1e635e38) entered blocking state machine # [ 32.196043] cni0: port 1(veth1e635e38) entered disabled state machine # [ 32.196065] veth1e635e38: entered allmulticast mode machine # [ 32.196149] veth1e635e38: entered promiscuous mode machine # machine # [ 32.209627] k3s[847]: I1001 08:24:33.026122 847 iptables.go:358] bootstrap done machine # [ 32.219395] cni0: port 1(veth1e635e38) entered blocking state machine # [ 32.219424] cni0: port 1(veth1e635e38) entered forwarding state machine # [ 32.243592] dhcpcd[619]: veth1e635e38: IAID b2:14:0b:a3 machine # [ 32.244706] dhcpcd[619]: veth1e635e38: adding address fe80::b488:b2ff:fe14:ba3 machine # [ 32.246534] k3s[847]: I1001 08:24:33.062904 847 iptables.go:358] bootstrap done machine # [ 32.344576] systemd[1]: Started libcontainer container 37587c6b84e8303eb240e9a09495cd4de613eb34d0f5f63e36cf761ff6dbcf38. machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 33.640617] dhcpcd[619]: flannel.1: soliciting an IPv6 router machine # [ 33.677162] systemd[1]: Started libcontainer container 17492c68a5f341ba9e5426361ec2b15f52a39f33b8e1037424273ef1df9ed301. machine # [ 33.789908] k3s[847]: I1001 08:24:34.606214 847 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/helm-install-niks3-p2vd4" podStartSLOduration=2.6061935800000002 podStartE2EDuration="2.60619358s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-10-01 08:24:32 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-10-01 08:24:34.60406378 +0000 UTC m=+15.559424881" watchObservedRunningTime="2026-10-01 08:24:34.60619358 +0000 UTC m=+15.561554681" machine # [ 33.987387] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="Started tunnel to 10.0.2.15:6443" machine # [ 33.989730] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="Stopped tunnel to 127.0.0.1:6443" machine # [ 33.992937] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="Connecting to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect" machine # [ 33.995675] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect" machine # [ 33.998622] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF" machine # [ 34.001645] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="Handling backend connection request [machine]" machine # [ 34.003884] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="Connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect" machine # [ 34.006414] k3s[847]: time="2026-10-01T08:24:34Z" level=info msg="Remotedialer connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect" machine # [ 34.009250] dhcpcd[619]: flannel.1: soliciting a DHCP lease machine # [ 34.048721] dhcpcd[619]: veth1e635e38: soliciting a DHCP lease machine # Error from server (NotFound): namespaces "niks3" not found machine # [ 34.969035] dhcpcd[619]: veth1e635e38: soliciting an IPv6 router machine # [ 35.028127] k3s[847]: I1001 08:24:35.844373 847 alloc.go:329] "allocated clusterIPs" service="niks3/niks3" clusterIPs={"IPv4":"10.43.241.32"} machine # [ 35.088185] k3s[847]: I1001 08:24:35.901541 847 controller.go:667] quota admission added evaluator for: cronjobs.batch machine # [ 35.144081] systemd[1]: cri-containerd-17492c68a5f341ba9e5426361ec2b15f52a39f33b8e1037424273ef1df9ed301.scope: Deactivated successfully. machine # [ 35.145931] systemd[1]: cri-containerd-17492c68a5f341ba9e5426361ec2b15f52a39f33b8e1037424273ef1df9ed301.scope: Consumed 908ms CPU time over 1.466s wall clock time, 35.9M memory peak, 4.5M incoming IP traffic, 96.4K outgoing IP traffic. machine # [ 35.252872] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-17492c68a5f341ba9e5426361ec2b15f52a39f33b8e1037424273ef1df9ed301-rootfs.mount: Deactivated successfully. machine # [ 35.467751] systemd[1]: Created slice libcontainer container kubepods-besteffort-poda0599d13_f90e_424a_94bb_8a528abff95e.slice. machine # [ 35.552115] k3s[847]: I1001 08:24:36.368841 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/a0599d13-f90e-424a-94bb-8a528abff95e-token\") pod \"niks3-5b6bd764d7-psqlw\" (UID: \"a0599d13-f90e-424a-94bb-8a528abff95e\") " pod="niks3/niks3-5b6bd764d7-psqlw" machine # [ 35.559256] k3s[847]: I1001 08:24:36.368906 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"oidc\" (UniqueName: \"kubernetes.io/configmap/a0599d13-f90e-424a-94bb-8a528abff95e-oidc\") pod \"niks3-5b6bd764d7-psqlw\" (UID: \"a0599d13-f90e-424a-94bb-8a528abff95e\") " pod="niks3/niks3-5b6bd764d7-psqlw" machine # [ 35.565960] k3s[847]: I1001 08:24:36.368935 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"db\" (UniqueName: \"kubernetes.io/secret/a0599d13-f90e-424a-94bb-8a528abff95e-db\") pod \"niks3-5b6bd764d7-psqlw\" (UID: \"a0599d13-f90e-424a-94bb-8a528abff95e\") " pod="niks3/niks3-5b6bd764d7-psqlw" machine # [ 35.575301] k3s[847]: I1001 08:24:36.368958 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"s3\" (UniqueName: \"kubernetes.io/secret/a0599d13-f90e-424a-94bb-8a528abff95e-s3\") pod \"niks3-5b6bd764d7-psqlw\" (UID: \"a0599d13-f90e-424a-94bb-8a528abff95e\") " pod="niks3/niks3-5b6bd764d7-psqlw" machine # [ 35.583329] k3s[847]: I1001 08:24:36.368984 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-v7hx6\" (UniqueName: \"kubernetes.io/projected/a0599d13-f90e-424a-94bb-8a528abff95e-kube-api-access-v7hx6\") pod \"niks3-5b6bd764d7-psqlw\" (UID: \"a0599d13-f90e-424a-94bb-8a528abff95e\") " pod="niks3/niks3-5b6bd764d7-psqlw" machine # [ 35.844996] cni0: port 2(veth849c3e66) entered blocking state machine # [ 35.845030] cni0: port 2(veth849c3e66) entered disabled state machine # [ 35.845069] veth849c3e66: entered allmulticast mode machine # [ 35.845180] veth849c3e66: entered promiscuous mode machine # [ 35.846629] (udev-worker)[1479]: Network interface NamePolicy= disabled on kernel command line. machine # [ 35.868018] cni0: port 2(veth849c3e66) entered blocking state machine # [ 35.868049] cni0: port 2(veth849c3e66) entered forwarding state machine # [ 35.890593] dhcpcd[619]: veth849c3e66: IAID 5b:8c:ac:43 machine # [ 35.891721] dhcpcd[619]: veth849c3e66: adding address fe80::e419:5bff:fe8c:ac43 machine # [ 35.978414] k3s[847]: I1001 08:24:36.795345 847 kuberuntime_manager.go:2172] "Updating runtime config through cri with podcidr" CIDR="10.42.0.0/24" machine # [ 35.982715] k3s[847]: I1001 08:24:36.799676 847 kubelet_network.go:48] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="10.42.0.0/24" machine # [ 35.996407] systemd[1]: Started libcontainer container f24b8c58e485af4ca59be50980ee9c177d6457d90959c636c80898d1eea60cd8. machine # [ 36.422792] dhcpcd[619]: veth849c3e66: soliciting a DHCP lease machine # [ 36.464748] systemd[1]: Started libcontainer container 63c1bd7adcc0fec5179431c9f7b5d0682c8c7a920ef8c8819422b3587fa18b5e. machine # [ 36.556128] postgres[1625]: [1625] ERROR: relation "goose_db_version" does not exist at character 36 machine # [ 36.557624] postgres[1625]: [1625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC machine # [ 36.711358] systemd[1]: cri-containerd-37587c6b84e8303eb240e9a09495cd4de613eb34d0f5f63e36cf761ff6dbcf38.scope: Deactivated successfully. machine # [ 36.747665] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-37587c6b84e8303eb240e9a09495cd4de613eb34d0f5f63e36cf761ff6dbcf38-rootfs.mount: Deactivated successfully. machine # [ 36.832823] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-37587c6b84e8303eb240e9a09495cd4de613eb34d0f5f63e36cf761ff6dbcf38-shm.mount: Deactivated successfully. machine # [ 36.875377] dhcpcd[619]: veth1e635e38: carrier lost[ 36.879062] cni0: port 1(veth1e635e38) entered disabled state machine # machine # [ 36.880308] veth1e635e38 (unregistering): left allmulticast mode machine # [ 36.880335] veth1e635e38 (unregistering): left promiscuous mode machine # [ 36.880347] cni0: port 1(veth1e635e38) entered disabled state machine # [ 36.909940] systemd[1]: run-netns-cni\x2dd98ca1a6\x2dc445\x2db1fe\x2d950e\x2d3c5c787c8c4d.mount: Deactivated successfully. machine # [ 36.926351] dhcpcd[619]: veth1e635e38: deleting address fe80::b488:b2ff:fe14:ba3 machine # [ 36.951719] k3s[847]: I1001 08:24:37.768048 847 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-5b6bd764d7-psqlw" podStartSLOduration=1.76802394 podStartE2EDuration="1.76802394s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-10-01 08:24:36 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-10-01 08:24:37.38844572 +0000 UTC m=+18.343806821" watchObservedRunningTime="2026-10-01 08:24:37.76802394 +0000 UTC m=+18.723385021" machine # [ 36.970056] k3s[847]: time="2026-10-01T08:24:37Z" level=info msg="Starting network policy controller version v2.6.3-k3s1, built on 1970-01-01T01:01:01Z, go1.26.7" machine # [ 36.972180] k3s[847]: I1001 08:24:37.786490 847 network_policy_controller.go:164] Starting network policy controller machine # [ 36.984592] dhcpcd[619]: veth1e635e38: removing interface machine # [ 37.063153] k3s[847]: I1001 08:24:37.880052 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-helm\") pod \"327b78eb-21e9-4a2a-a4f4-950998887667\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " machine # [ 37.068182] k3s[847]: I1001 08:24:37.880108 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-tmp\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-tmp\") pod \"327b78eb-21e9-4a2a-a4f4-950998887667\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " machine # [ 37.072411] k3s[847]: I1001 08:24:37.880139 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/configmap/327b78eb-21e9-4a2a-a4f4-950998887667-content\" (UniqueName: \"kubernetes.io/configmap/327b78eb-21e9-4a2a-a4f4-950998887667-content\") pod \"327b78eb-21e9-4a2a-a4f4-950998887667\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " machine # [ 37.076805] k3s[847]: I1001 08:24:37.880167 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-cache\") pod \"327b78eb-21e9-4a2a-a4f4-950998887667\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " machine # [ 37.081156] k3s[847]: I1001 08:24:37.880201 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-values\" (UniqueName: \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-values\") pod \"327b78eb-21e9-4a2a-a4f4-950998887667\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " machine # [ 37.085414] k3s[847]: I1001 08:24:37.880227 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-kube-api-access-24kw7\" (UniqueName: \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-kube-api-access-24kw7\") pod \"327b78eb-21e9-4a2a-a4f4-950998887667\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " machine # [ 37.090038] k3s[847]: I1001 08:24:37.880248 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-config\") pod \"327b78eb-21e9-4a2a-a4f4-950998887667\" (UID: \"327b78eb-21e9-4a2a-a4f4-950998887667\") " machine # [ 37.094894] k3s[847]: I1001 08:24:37.894362 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-helm" pod "327b78eb-21e9-4a2a-a4f4-950998887667" (UID: "327b78eb-21e9-4a2a-a4f4-950998887667"). InnerVolumeSpecName "klipper-helm". PluginName "kubernetes.io/empty-dir", VolumeGIDValue "" machine # [ 37.100443] k3s[847]: I1001 08:24:37.900261 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/configmap/327b78eb-21e9-4a2a-a4f4-950998887667-content" pod "327b78eb-21e9-4a2a-a4f4-950998887667" (UID: "327b78eb-21e9-4a2a-a4f4-950998887667"). InnerVolumeSpecName "content". PluginName "kubernetes.io/configmap", VolumeGIDValue "" machine # [ 37.105083] k3s[847]: I1001 08:24:37.908180 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-tmp" pod "327b78eb-21e9-4a2a-a4f4-950998887667" (UID: "327b78eb-21e9-4a2a-a4f4-950998887667"). InnerVolumeSpecName "tmp". PluginName "kubernetes.io/empty-dir", VolumeGIDValue "" machine # [ 37.110203] k3s[847]: I1001 08:24:37.908485 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-config" pod "327b78eb-21e9-4a2a-a4f4-950998887667" (UID: "327b78eb-21e9-4a2a-a4f4-950998887667"). InnerVolumeSpecName "klipper-config". PluginName "kubernetes.io/empty-dir", VolumeGIDValue "" machine # [ 37.115716] k3s[847]: I1001 08:24:37.910148 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-cache" pod "327b78eb-21e9-4a2a-a4f4-950998887667" (UID: "327b78eb-21e9-4a2a-a4f4-950998887667"). InnerVolumeSpecName "klipper-cache". PluginName "kubernetes.io/empty-dir", VolumeGIDValue "" machine # [ 37.121021] k3s[847]: I1001 08:24:37.918124 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-values" pod "327b78eb-21e9-4a2a-a4f4-950998887667" (UID: "327b78eb-21e9-4a2a-a4f4-950998887667"). InnerVolumeSpecName "values". PluginName "kubernetes.io/projected", VolumeGIDValue "" machine # [ 37.125609] k3s[847]: I1001 08:24:37.937887 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-kube-api-access-24kw7" pod "327b78eb-21e9-4a2a-a4f4-950998887667" (UID: "327b78eb-21e9-4a2a-a4f4-950998887667"). InnerVolumeSpecName "kube-api-access-24kw7". PluginName "kubernetes.io/projected", VolumeGIDValue "" machine # [ 37.142809] k3s[847]: I1001 08:24:37.959727 847 network_policy_controller.go:179] Starting network policy controller full sync goroutine machine # [ 37.164081] k3s[847]: I1001 08:24:37.980848 847 reconciler_common.go:299] "Volume detached for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-helm\") on node \"machine\" DevicePath \"\"" machine # [ 37.167468] k3s[847]: I1001 08:24:37.980885 847 reconciler_common.go:299] "Volume detached for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-tmp\") on node \"machine\" DevicePath \"\"" machine # [ 37.170490] k3s[847]: I1001 08:24:37.980896 847 reconciler_common.go:299] "Volume detached for volume \"content\" (UniqueName: \"kubernetes.io/configmap/327b78eb-21e9-4a2a-a4f4-950998887667-content\") on node \"machine\" DevicePath \"\"" machine # [ 37.173498] k3s[847]: I1001 08:24:37.980913 847 reconciler_common.go:299] "Volume detached for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-cache\") on node \"machine\" DevicePath \"\"" machine # [ 37.176733] k3s[847]: I1001 08:24:37.980927 847 reconciler_common.go:299] "Volume detached for volume \"values\" (UniqueName: \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-values\") on node \"machine\" DevicePath \"\"" machine # [ 37.179823] k3s[847]: I1001 08:24:37.980937 847 reconciler_common.go:299] "Volume detached for volume \"kube-api-access-24kw7\" (UniqueName: \"kubernetes.io/projected/327b78eb-21e9-4a2a-a4f4-950998887667-kube-api-access-24kw7\") on node \"machine\" DevicePath \"\"" machine # [ 37.183175] k3s[847]: I1001 08:24:37.980952 847 reconciler_common.go:299] "Volume detached for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/327b78eb-21e9-4a2a-a4f4-950998887667-klipper-config\") on node \"machine\" DevicePath \"\"" machine # [ 37.253652] systemd[1]: var-lib-kubelet-pods-327b78eb\x2d21e9\x2d4a2a\x2da4f4\x2d950998887667-volumes-kubernetes.io\x7eprojected-values.mount: Deactivated successfully. machine # [ 37.256924] systemd[1]: var-lib-kubelet-pods-327b78eb\x2d21e9\x2d4a2a\x2da4f4\x2d950998887667-volumes-kubernetes.io\x7eprojected-kube\x2dapi\x2daccess\x2d24kw7.mount: Deactivated successfully. machine # [ 37.259529] systemd[1]: var-lib-kubelet-pods-327b78eb\x2d21e9\x2d4a2a\x2da4f4\x2d950998887667-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dhelm.mount: Deactivated successfully. machine # [ 37.261975] systemd[1]: var-lib-kubelet-pods-327b78eb\x2d21e9\x2d4a2a\x2da4f4\x2d950998887667-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dconfig.mount: Deactivated successfully. machine # [ 37.264401] systemd[1]: var-lib-kubelet-pods-327b78eb\x2d21e9\x2d4a2a\x2da4f4\x2d950998887667-volumes-kubernetes.io\x7eempty\x2ddir-tmp.mount: Deactivated successfully. machine # [ 37.266471] systemd[1]: var-lib-kubelet-pods-327b78eb\x2d21e9\x2d4a2a\x2da4f4\x2d950998887667-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dcache.mount: Deactivated successfully. machine # [ 37.433058] systemd[1]: Removed slice libcontainer container kubepods-burstable-pod327b78eb_21e9_4a2a_a4f4_950998887667.slice. machine # [ 37.435267] systemd[1]: kubepods-burstable-pod327b78eb_21e9_4a2a_a4f4_950998887667.slice: Consumed 934ms CPU time over 5.902s wall clock time, 36.1M memory peak, 4.5M incoming IP traffic, 96.4K outgoing IP traffic. machine # [ 37.695559] k3s[847]: I1001 08:24:38.512484 847 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="37587c6b84e8303eb240e9a09495cd4de613eb34d0f5f63e36cf761ff6dbcf38" machine # [ 37.701446] k3s[847]: E1001 08:24:38.512726 847 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-pod327b78eb_21e9_4a2a_a4f4_950998887667.slice: openat2 /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-pod327b78eb_21e9_4a2a_a4f4_950998887667.slice/memory.max: no such file or directory" podName="helm-install-niks3-p2vd4" machine # [ 37.712806] k3s[847]: E1001 08:24:38.512825 847 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-pod327b78eb_21e9_4a2a_a4f4_950998887667.slice: openat2 /sys/fs/cgroup/kubepods.slice/kubepods-burstable.slice/kubepods-burstable-pod327b78eb_21e9_4a2a_a4f4_950998887667.slice/cpu.max: no such file or directory" podName="helm-install-niks3-p2vd4" machine # [ 37.890716] dhcpcd[619]: veth849c3e66: soliciting an IPv6 router machine # [ 39.004351] dhcpcd[619]: flannel.1: probing for an IPv4LL address machine # [ 41.421133] dhcpcd[619]: veth849c3e66: probing for an IPv4LL address machine: (finished: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s, in 16.62 seconds) machine: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true machine: (finished: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true, in 0.21 seconds) machine: waiting for success: curl -sf http://localhost:30051/readyz | grep OK machine: (finished: waiting for success: curl -sf http://localhost:30051/readyz | grep OK, in 0.05 seconds) (finished: subtest: chart deploys and becomes ready, in 16.87 seconds) machine: waiting for success: kubectl -n ci get sa builder machine: (finished: waiting for success: kubectl -n ci get sa builder, in 0.19 seconds) machine: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt machine: (finished: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt, in 0.19 seconds) machine: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt machine: (finished: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt, in 0.17 seconds) machine: must succeed: readlink -f /run/current-system/sw/bin/niks3 machine: (finished: must succeed: readlink -f /run/current-system/sw/bin/niks3, in 0.02 seconds) subtest: allowed service account can push via workload identity machine: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0 2>&1 machine # [ 44.158587] dhcpcd[619]: flannel.1: using IPv4LL address 169.254.130.99 machine # [ 44.158875] dhcpcd[619]: flannel.1: adding route to 169.254.0.0/16 machine # [ 45.642736] dhcpcd[619]: flannel.1: no IPv6 Routers available machine # [ 46.310641] dhcpcd[619]: veth849c3e66: using IPv4LL address 169.254.219.37 machine # [ 46.310978] dhcpcd[619]: veth849c3e66: adding route to 169.254.0.0/16 machine # [ 47.468953] cni0: port 1(vethc52fb9bf) entered blocking state machine # [ 47.468989] cni0: port 1(vethc52fb9bf) entered disabled state machine # [ 47.469027] vethc52fb9bf: entered allmulticast mode machine # [ 47.469175] vethc52fb9bf: entered promiscuous mode machine # [ 47.487674] cni0: port 1(vethc52fb9bf) entered blocking state machine # [ 47.487703] cni0: port 1(vethc52fb9bf) entered forwarding state machine # [ 47.548475] (udev-worker)[1954]: Network interface NamePolicy= disabled on kernel command line. machine # [ 47.587520] dhcpcd[619]: vethc52fb9bf: IAID 12:ce:22:f5 machine # [ 47.588545] dhcpcd[619]: vethc52fb9bf: adding address fe80::8828:12ff:fece:22f5 machine # [ 47.616727] systemd[1]: Started libcontainer container 773367d375c4627998b016bbadd1dc7d1c107e86928d8414fa3117dd909a74ba. machine # [ 47.729972] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount48520332.mount: Deactivated successfully. machine # [ 48.625152] systemd[1]: Started libcontainer container bfeba2e8d58ca0d424d903753be78af595e06cd6ca0406bbd9482be12a6d1ae2. machine # [ 48.747203] k3s[847]: I1001 08:24:49.563067 847 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/coredns-54996dc9b4-xxg46" podStartSLOduration=17.5630377 podStartE2EDuration="17.5630377s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-10-01 08:24:32 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-10-01 08:24:49.56291694 +0000 UTC m=+30.518278041" watchObservedRunningTime="2026-10-01 08:24:49.5630377 +0000 UTC m=+30.518398801" machine # [ 48.781712] dhcpcd[619]: vethc52fb9bf: soliciting a DHCP lease machine # [ 49.123606] dhcpcd[619]: vethc52fb9bf: soliciting an IPv6 router machine # [ 49.894359] dhcpcd[619]: veth849c3e66: no IPv6 Routers available machine # [ 53.783048] dhcpcd[619]: vethc52fb9bf: probing for an IPv4LL address machine # [ 58.582324] dhcpcd[619]: vethc52fb9bf: using IPv4LL address 169.254.129.120 machine # [ 58.584113] dhcpcd[619]: vethc52fb9bf: adding route to 169.254.0.0/16 machine: (finished: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0 2>&1, in 16.18 seconds) machine: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s.narinfo machine: (finished: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s.narinfo, in 0.03 seconds) (finished: subtest: allowed service account can push via workload identity, in 16.21 seconds) subtest: write scope does not grant admin machine: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status 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) (finished: subtest: write scope does not grant admin, in 0.03 seconds) subtest: other service accounts are rejected machine: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0 2>&1 machine: (finished: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0 2>&1, in 0.13 seconds) (finished: subtest: other service accounts are rejected, in 0.13 seconds) subtest: gc cronjob runs against the service machine: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual machine: (finished: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual, in 0.18 seconds) machine: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s machine # [ 59.193185] systemd[1]: Created slice libcontainer container kubepods-besteffort-podb886fd9b_816a_4433_8ec4_d8071fd9c006.slice. machine # [ 59.319243] k3s[847]: I1001 08:25:00.135763 847 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/b886fd9b-816a-4433-8ec4-d8071fd9c006-token\") pod \"gc-manual-hpbgr\" (UID: \"b886fd9b-816a-4433-8ec4-d8071fd9c006\") " pod="niks3/gc-manual-hpbgr" machine # [ 59.537859] cni0: port 3(veth264f8efd) entered blocking state machine # [ 59.537908] cni0: port 3(veth264f8efd) entered disabled state machine # [ 59.537940] veth264f8efd: entered allmulticast mode machine # [ 59.538111] veth264f8efd: entered promiscuous mode machine # [ 59.559675] cni0: port 3(veth264f8efd) entered blocking state machine # [ 59.559708] cni0: port 3(veth264f8efd) entered forwarding state machine # [ 59.611492] (udev-worker)[2219]: Network interface NamePolicy= disabled on kernel command line. machine # [ 59.663278] dhcpcd[619]: veth264f8efd: IAID 92:60:7a:60 machine # [ 59.664400] dhcpcd[619]: veth264f8efd: adding address fe80::48fd:92ff:fe60:7a60 machine # [ 59.696418] systemd[1]: Started libcontainer container 7ea559ccfd58062f0bf4f50412c93f1c4c5ea72237034ae5500d429ee6325e26. machine # [ 59.832518] systemd[1]: Started libcontainer container 7d3307692d6bfe48c62ba78e1f0d661012b357c5843e30a909c6378eb2e90291. machine # [ 59.915687] k3s[847]: I1001 08:25:00.731568 847 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/gc-manual-hpbgr" podStartSLOduration=1.7315266999999999 podStartE2EDuration="1.7315267s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-10-01 08:24:59 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-10-01 08:25:00.73059264 +0000 UTC m=+41.685953741" watchObservedRunningTime="2026-10-01 08:25:00.7315267 +0000 UTC m=+41.686887801" machine # [ 59.945168] dhcpcd[619]: veth264f8efd: soliciting a DHCP lease machine # [ 61.127981] dhcpcd[619]: vethc52fb9bf: no IPv6 Routers available machine # [ 61.899467] systemd[1]: cri-containerd-7d3307692d6bfe48c62ba78e1f0d661012b357c5843e30a909c6378eb2e90291.scope: Deactivated successfully. machine # [ 61.903309] systemd[1]: cri-containerd-7d3307692d6bfe48c62ba78e1f0d661012b357c5843e30a909c6378eb2e90291.scope: Consumed 36ms CPU time over 2.066s wall clock time, 3.8M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic. machine # [ 61.955774] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-7d3307692d6bfe48c62ba78e1f0d661012b357c5843e30a909c6378eb2e90291-rootfs.mount: Deactivated successfully. machine # [ 62.446081] dhcpcd[619]: veth264f8efd: soliciting an IPv6 router machine # [ 63.823262] systemd[1]: cri-containerd-7ea559ccfd58062f0bf4f50412c93f1c4c5ea72237034ae5500d429ee6325e26.scope: Deactivated successfully. machine # [ 63.878019] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-7ea559ccfd58062f0bf4f50412c93f1c4c5ea72237034ae5500d429ee6325e26-rootfs.mount: Deactivated successfully. machine # [ 63.912794] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-7ea559ccfd58062f0bf4f50412c93f1c4c5ea72237034ae5500d429ee6325e26-shm.mount: Deactivated successfully. machine # [ 63.960798] cni0: port 3(veth264f8efd) entered disabled state machine # [ 63.957136] dhcpcd[619]: veth264f8efd: carrier lost machine # [ 63.965007] veth264f8efd (unregistering): left allmulticast mode machine # [ 63.965037] veth264f8efd (unregistering): left promiscuous mode machine # [ 63.965052] cni0: port 3(veth264f8efd) entered disabled state machine # [ 63.992678] systemd[1]: run-netns-cni\x2d64ffe497\x2dd136\x2db16b\x2d1ce5\x2de79943587c8f.mount: Deactivated successfully. machine # [ 64.018318] dhcpcd[619]: veth264f8efd: deleting address fe80::48fd:92ff:fe60:7a60 machine # [ 64.076342] dhcpcd[619]: veth264f8efd: removing interface machine # [ 64.154705] k3s[847]: I1001 08:25:04.971244 847 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/secret/b886fd9b-816a-4433-8ec4-d8071fd9c006-token\" (UniqueName: \"kubernetes.io/secret/b886fd9b-816a-4433-8ec4-d8071fd9c006-token\") pod \"b886fd9b-816a-4433-8ec4-d8071fd9c006\" (UID: \"b886fd9b-816a-4433-8ec4-d8071fd9c006\") " machine # [ 64.160397] systemd[1]: var-lib-kubelet-pods-b886fd9b\x2d816a\x2d4433\x2d8ec4\x2dd8071fd9c006-volumes-kubernetes.io\x7esecret-token.mount: Deactivated successfully. machine # [ 64.166187] k3s[847]: I1001 08:25:04.982334 847 operation_generator.go:782] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/b886fd9b-816a-4433-8ec4-d8071fd9c006-token" pod "b886fd9b-816a-4433-8ec4-d8071fd9c006" (UID: "b886fd9b-816a-4433-8ec4-d8071fd9c006"). InnerVolumeSpecName "token". PluginName "kubernetes.io/secret", VolumeGIDValue "" machine # [ 64.255332] k3s[847]: I1001 08:25:05.072214 847 reconciler_common.go:299] "Volume detached for volume \"token\" (UniqueName: \"kubernetes.io/secret/b886fd9b-816a-4433-8ec4-d8071fd9c006-token\") on node \"machine\" DevicePath \"\"" machine # [ 64.806222] k3s[847]: I1001 08:25:05.623068 847 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="7ea559ccfd58062f0bf4f50412c93f1c4c5ea72237034ae5500d429ee6325e26" machine # [ 64.817449] systemd[1]: Removed slice libcontainer container kubepods-besteffort-podb886fd9b_816a_4433_8ec4_d8071fd9c006.slice. machine # [ 64.823912] systemd[1]: kubepods-besteffort-podb886fd9b_816a_4433_8ec4_d8071fd9c006.slice: Consumed 63ms CPU time over 5.624s wall clock time, 4.6M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic. machine: (finished: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s, in 5.70 seconds) (finished: subtest: gc cronjob runs against the service, in 5.89 seconds) subtest: helm test hook passes machine: must succeed: helm test -n niks3 niks3 --timeout 2m >&2 machine # [ 66.319627] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod95aa6571_7d6a_43bb_b3b1_d005a78fb009.slice. machine # [ 66.385501] cni0: port 3(vethd01fb015) entered blocking state machine # [ 66.385533] cni0: port 3(vethd01fb015) entered disabled state machine # [ 66.385553] vethd01fb015: entered allmulticast mode machine # [ 66.384590] (udev-worker)[2434]: Network interface NamePolicy= disabled on kernel command line.[ 66.385643] vethd01fb015: entered promiscuous mode machine # machine # [ 66.407617] cni0: port 3(vethd01fb015) entered blocking state machine # [ 66.407647] cni0: port 3(vethd01fb015) entered forwarding state machine # [ 66.432753] dhcpcd[619]: vethd01fb015: IAID 60:9d:a1:1d machine # [ 66.433700] dhcpcd[619]: vethd01fb015: adding address fe80::b4bc:60ff:fe9d:a11d machine # [ 66.548378] systemd[1]: Started libcontainer container dd968006e24803b4a610194c170bb6f4e195a785a9ab07ee012e89bff6673452. machine # [ 66.676544] systemd[1]: Started libcontainer container 148f1ebe3f7dc9f050f9f2e5abcbdf72c5f4102590b88608abef349dc36f5b2b. machine # [ 66.741611] systemd[1]: cri-containerd-148f1ebe3f7dc9f050f9f2e5abcbdf72c5f4102590b88608abef349dc36f5b2b.scope: Deactivated successfully. machine # [ 66.744231] systemd[1]: cri-containerd-148f1ebe3f7dc9f050f9f2e5abcbdf72c5f4102590b88608abef349dc36f5b2b.scope: Consumed 29ms CPU time over 64ms wall clock time, 3.8M memory peak, 693B incoming IP traffic, 547B outgoing IP traffic. machine # [ 66.792878] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-148f1ebe3f7dc9f050f9f2e5abcbdf72c5f4102590b88608abef349dc36f5b2b-rootfs.mount: Deactivated successfully. machine # [ 67.509022] dhcpcd[619]: vethd01fb015: soliciting a DHCP lease machine # [ 67.836636] systemd[1]: cri-containerd-dd968006e24803b4a610194c170bb6f4e195a785a9ab07ee012e89bff6673452.scope: Deactivated successfully. machine # [ 67.889817] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-dd968006e24803b4a610194c170bb6f4e195a785a9ab07ee012e89bff6673452-rootfs.mount: Deactivated successfully. machine # [ 67.924773] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-dd968006e24803b4a610194c170bb6f4e195a785a9ab07ee012e89bff6673452-shm.mount: Deactivated successfully. machine # [ 67.972526] cni0: port 3(vethd01fb015) entered disabled state machine # [ 67.969496] dhcpcd[619]: vethd01fb015: carrier lost machine # [ 67.975439] vethd01fb015 (unregistering): left allmulticast mode machine # [ 67.975471] vethd01fb015 (unregistering): left promiscuous mode machine # [ 67.975487] cni0: port 3(vethd01fb015) entered disabled state machine # [ 68.002924] systemd[1]: run-netns-cni\x2d15a84f3e\x2dfdaf\x2db331\x2d3d7b\x2dfd436a7239bc.mount: Deactivated successfully. machine # [ 68.026784] dhcpcd[619]: vethd01fb015: deleting address fe80::b4bc:60ff:fe9d:a11d machine # NAME: niks3 machine # LAST DEPLOYED: Thu Oct 1 08:24:35 2026 machine # NAMESPACE: niks3 machine # STATUS: deployed machine # REVISION: 1 machine # DESCRIPTION: Install complete machine # TEST SUITE: niks3-test machine # Last Started: Thu Oct 1 08:25:06 2026 machine # Last Completed: Thu Oct 1 08:25:08 2026 machine # Phase: Succeeded machine: (finished: must succeed: helm test -n niks3 niks3 --timeout 2m >&2, in 3.23 seconds) (finished: subtest: helm test hook passes, in 3.23 seconds) (finished: run the VM test script, in 68.80 seconds) machine # [ 68.120507] dhcpcd[619]: vethd01fb015: removing interface test script finished in 68.86s cleanup kill QemuMachine (pid 45) machine # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/3fl7bdkdxk2k4nssy1d1161isbzn6bsr-python3-3.14.7/bin/python3.14) machine # [2026-10-01T08:25:09Z INFO virtiofsd] Client disconnected, shutting down machine # [2026-10-01T08:25:09Z INFO virtiofsd] Client disconnected, shutting down machine # [2026-10-01T08:25:09Z INFO virtiofsd] Client disconnected, shutting down (finished: cleanup, in 0.81 seconds) additionally exposed symbols: machine, vlan1, 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_ssh time=2026-10-01T08:24:58.642Z level=INFO msg="Uploading 8 paths to localhost (0 already cached)" time=2026-10-01T08:24:58.642Z level=INFO msg="Uploading waax852balprvsvdziyaf1h7r3ldvakg-xgcc-15.3.0-libgcc (150.1KB)" time=2026-10-01T08:24:58.642Z level=INFO msg="Uploading n7aaryickpnkwwmmkg7xgnlihmmsh55w-mailcap-2.1.54 (116.6KB)" time=2026-10-01T08:24:58.643Z level=INFO msg="Uploading h0hd048jzxs7fx9a6g75jwrrhbg50bp8-libunistring-1.4.2 (2.0MB)" time=2026-10-01T08:24:58.645Z level=INFO msg="Uploading m54cs0m994hc3n9lax7sg98sgy729qsa-glibc-2.42-84 (44.4MB)" time=2026-10-01T08:24:58.648Z level=INFO msg="Uploading i8an849ir6g3f4n2wrsm88s2qgrzjayq-tzdata-2026c (2.0MB)" time=2026-10-01T08:24:58.648Z level=INFO msg="Uploading na3qajp3ja0w9yxcsqck86phm9ddhwx2-iana-etc-20251215 (557.8KB)" time=2026-10-01T08:24:58.651Z level=INFO msg="Uploading 0s40b0an0cz4vypbji92cb7qbr65icl4-libidn2-2.3.8 (366.1KB)" time=2026-10-01T08:24:58.653Z level=INFO msg="Uploading g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0 (7.2MB)" time=2026-10-01T08:24:59.569Z level=INFO msg="Uploading 8 narinfos" time=2026-10-01T08:24:59.609Z level=INFO msg="Upload complete. (16.09s)"