vm-test-run-nixos-test-k3s
checks.x86_64-linux.nixos-test-k3s
· build #228
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Test will time out and terminate in 3600.0 seconds6run the VM test script7machine: waiting for unit k3s.service8machine: waiting for the VM to finish booting9machine: starting vm10machine: QEMU running (pid 45)11machine # Disk image does not exist, creating the virtualisation disk image...12machine # Formatting '/build/vm-state-machine/tmp.BmYodA1kA3', fmt=raw size=858993459213machine # mke2fs 1.47.4 (6-Mar-2025)14machine # Discarding device blocks: 0/2097152 done15machine # Creating filesystem with 2097152 4k blocks and 524288 inodes16machine # Filesystem UUID: 9bb956bf-81dc-4ac2-b27d-c9d678fa930a17machine # Superblock backups stored on blocks:18machine # 32768, 98304, 163840, 229376, 294912, 819200, 884736, 160563219machine # 20machine # Allocating group tables: 0/64 done21machine # Writing inode tables: 0/64 done22machine # Creating journal (16384 blocks): done23machine # Writing superblocks and filesystem accounting information: 0/64 done24machine # 25machine # Virtualisation disk image created.26machine # Starting virtiofs daemons...27machine # [2026-09-20T15:39:07Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)28machine # [2026-09-20T15:39:07Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether29machine # [2026-09-20T15:39:07Z INFO virtiofsd] Waiting for vhost-user socket connection...30machine # [2026-09-20T15:39:07Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)31machine # [2026-09-20T15:39:07Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether32machine # [2026-09-20T15:39:07Z INFO virtiofsd] Waiting for vhost-user socket connection...33machine # [2026-09-20T15:39:07Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)34machine # [2026-09-20T15:39:07Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether35machine # [2026-09-20T15:39:07Z INFO virtiofsd] Waiting for vhost-user socket connection...36machine # [2026-09-20T15:39:07Z INFO virtiofsd] Client connected, servicing requests37machine # [2026-09-20T15:39:07Z INFO virtiofsd] Client connected, servicing requests38machine # [2026-09-20T15:39:07Z INFO virtiofsd] Client connected, servicing requests39machine # SeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)40machine # 41machine # 42machine # iPXE (http://ipxe.org) 00:02.0 CA00 PCI2.10 PnP PMM+7EFCC730+7EF2C730 CA0043machine # Press Ctrl-B to configure iPXE (PCI 00:02.0)...44machine # 45machine # 46machine # 47machine # 48machine # iPXE (http://ipxe.org) 00:05.0 CB00 PCI2.10 PnP PMM 7EFCC730 7EF2C730 CB0049machine # Press Ctrl-B to configure iPXE (PCI 00:05.0)...50machine # 51machine # 52machine # Booting from ROM...53machine # Probing EDD (edd=off to disable)... o[ 0.000000] Linux version 6.18.51 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT_DYNAMIC Fri Sep 11 09:49:46 UTC 202654machine # [ 0.000000] Command line: console=ttyS0 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/wmj0aysya0djq9bq63k8kccvmvzzgmv8-nixos-system-machine-test/init regInfo=/nix/store/4akkvsap5i9bv821dkp5pvindfc7acby-closure-info/registration console=ttyS0,115200n8 console=tty055machine # [ 0.000000] BIOS-provided physical RAM map:56machine # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable57machine # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved58machine # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved59machine # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007ffd7fff] usable60machine # [ 0.000000] BIOS-e820: [mem 0x000000007ffd8000-0x000000007fffffff] reserved61machine # [ 0.000000] BIOS-e820: [mem 0x00000000b0000000-0x00000000bfffffff] reserved62machine # [ 0.000000] BIOS-e820: [mem 0x00000000fed1c000-0x00000000fed1ffff] reserved63machine # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved64machine # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved65machine # [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000013fffffff] usable66machine # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved67machine # [ 0.000000] NX (Execute Disable) protection: active68machine # [ 0.000000] APIC: Static calls initialized69machine # [ 0.000000] SMBIOS 2.8 present.70machine # [ 0.000000] DMI: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/201471machine # [ 0.000000] DMI: Memory slots populated: 1/172machine # [ 0.000000] Hypervisor detected: KVM73machine # [ 0.000000] last_pfn = 0x7ffd8 max_arch_pfn = 0x1000000000074machine # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d0075machine # [ 0.000000] kvm-clock: using sched offset of 518918119 cycles76machine # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns77machine # [ 0.000005] tsc: Detected 2400.012 MHz processor78machine # [ 0.000811] last_pfn = 0x140000 max_arch_pfn = 0x1000000000079machine # [ 0.000837] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs80machine # [ 0.000840] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT81machine # [ 0.000878] last_pfn = 0x7ffd8 max_arch_pfn = 0x1000000000082machine # [ 0.002728] found SMP MP-table at [mem 0x000f5450-0x000f545f]83machine # [ 0.002739] Using GB pages for direct mapping84machine # [ 0.002846] RAMDISK: [mem 0x7e36d000-0x7ffcffff]85machine # [ 0.002854] ACPI: Early table checksum verification disabled86machine # [ 0.002856] ACPI: RSDP 0x00000000000F5250 000014 (v00 BOCHS )87machine # [ 0.002860] ACPI: RSDT 0x000000007FFE247D 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)88machine # [ 0.002864] ACPI: FACP 0x000000007FFE226D 0000F4 (v03 BOCHS BXPC 00000001 BXPC 00000001)89machine # [ 0.002871] ACPI: DSDT 0x000000007FFE0040 00222D (v01 BOCHS BXPC 00000001 BXPC 00000001)90machine # [ 0.002874] ACPI: FACS 0x000000007FFE0000 00004091machine # [ 0.002875] ACPI: APIC 0x000000007FFE2361 000080 (v03 BOCHS BXPC 00000001 BXPC 00000001)92machine # [ 0.002877] ACPI: HPET 0x000000007FFE23E1 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)93machine # [ 0.002878] ACPI: MCFG 0x000000007FFE2419 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001)94machine # [ 0.002880] ACPI: WAET 0x000000007FFE2455 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)95machine # [ 0.002881] ACPI: Reserving FACP table memory at [mem 0x7ffe226d-0x7ffe2360]96machine # [ 0.002882] ACPI: Reserving DSDT table memory at [mem 0x7ffe0040-0x7ffe226c]97machine # [ 0.002883] ACPI: Reserving FACS table memory at [mem 0x7ffe0000-0x7ffe003f]98machine # [ 0.002883] ACPI: Reserving APIC table memory at [mem 0x7ffe2361-0x7ffe23e0]99machine # [ 0.002884] ACPI: Reserving HPET table memory at [mem 0x7ffe23e1-0x7ffe2418]100machine # [ 0.002884] ACPI: Reserving MCFG table memory at [mem 0x7ffe2419-0x7ffe2454]101machine # [ 0.002885] ACPI: Reserving WAET table memory at [mem 0x7ffe2455-0x7ffe247c]102machine # [ 0.003121] No NUMA configuration found103machine # [ 0.003122] Faking a node at [mem 0x0000000000000000-0x000000013fffffff]104machine # [ 0.003124] NODE_DATA(0) allocated [mem 0x13fffa780-0x13ffffcff]105machine # [ 0.005302] Zone ranges:106machine # [ 0.005303] DMA [mem 0x0000000000001000-0x0000000000ffffff]107machine # [ 0.005304] DMA32 [mem 0x0000000001000000-0x00000000ffffffff]108machine # [ 0.005305] Normal [mem 0x0000000100000000-0x000000013fffffff]109machine # [ 0.005306] Device empty110machine # [ 0.005307] Movable zone start for each node111machine # [ 0.005308] Early memory node ranges112machine # [ 0.005308] node 0: [mem 0x0000000000001000-0x000000000009efff]113machine # [ 0.005309] node 0: [mem 0x0000000000100000-0x000000007ffd7fff]114machine # [ 0.005310] node 0: [mem 0x0000000100000000-0x000000013fffffff]115machine # [ 0.005311] Initmem setup node 0 [mem 0x0000000000001000-0x000000013fffffff]116machine # [ 0.005330] On node 0, zone DMA: 1 pages in unavailable ranges117machine # [ 0.005584] On node 0, zone DMA: 97 pages in unavailable ranges118machine # [ 0.056384] On node 0, zone Normal: 40 pages in unavailable ranges119machine # [ 0.056847] ACPI: PM-Timer IO Port: 0x608120machine # [ 0.056859] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])121machine # [ 0.056888] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23122machine # [ 0.056891] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)123machine # [ 0.056893] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)124machine # [ 0.056894] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)125machine # [ 0.056895] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)126machine # [ 0.056896] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)127machine # [ 0.056899] ACPI: Using ACPI (MADT) for SMP configuration information128machine # [ 0.056900] ACPI: HPET id: 0x8086a201 base: 0xfed00000129machine # [ 0.056904] TSC deadline timer available130machine # [ 0.056908] CPU topo: Max. logical packages: 1131machine # [ 0.056909] CPU topo: Max. logical dies: 1132machine # [ 0.056909] CPU topo: Max. dies per package: 1133machine # [ 0.056913] CPU topo: Max. threads per core: 1134machine # [ 0.056913] CPU topo: Num. cores per package: 2135machine # [ 0.056914] CPU topo: Num. threads per package: 2136machine # [ 0.056914] CPU topo: Allowing 2 present CPUs plus 0 hotplug CPUs137machine # [ 0.056935] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()138machine # [ 0.056951] kvm-guest: KVM setup pv remote TLB flush139machine # [ 0.056953] kvm-guest: setup PV sched yield140machine # [ 0.056962] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]141machine # [ 0.056964] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]142machine # [ 0.056965] PM: hibernation: Registered nosave memory: [mem 0x7ffd8000-0xffffffff]143machine # [ 0.056966] [mem 0xc0000000-0xfed1bfff] available for PCI devices144machine # [ 0.056968] Booting paravirtualized kernel on KVM145machine # [ 0.056971] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns146machine # [ 0.061406] setup_percpu: NR_CPUS:384 nr_cpumask_bits:2 nr_cpu_ids:2 nr_node_ids:1147machine # [ 0.063651] percpu: Embedded 98 pages/cpu s278528 r8192 d114688 u1048576148machine # [ 0.063700] kvm-guest: PV spinlocks enabled149machine # [ 0.063702] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear)150machine # [ 0.063704] Kernel command line: console=ttyS0 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/wmj0aysya0djq9bq63k8kccvmvzzgmv8-nixos-system-machine-test/init regInfo=/nix/store/4akkvsap5i9bv821dkp5pvindfc7acby-closure-info/registration console=ttyS0,115200n8 console=tty0151machine # [ 0.063797] Unknown kernel command line parameters "regInfo=/nix/store/4akkvsap5i9bv821dkp5pvindfc7acby-closure-info/registration", will be passed to user space.152machine # [ 0.063809] random: crng init done153machine # [ 0.063810] printk: log buffer data + meta data: 262144 + 917504 = 1179648 bytes154machine # [ 0.067896] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)155machine # [ 0.069946] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)156machine # [ 0.069991] software IO TLB: area num 2.157machine # [ 0.139368] Fallback order for Node 0: 0158machine # [ 0.139375] Built 1 zonelists, mobility grouping on. Total pages: 786294159machine # [ 0.139377] Policy zone: Normal160machine # [ 0.141706] mem auto-init: stack:all(zero), heap alloc:on, heap free:off161machine # [ 0.146953] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1162machine # [ 0.153303] allocated 6291456 bytes of page_ext163machine # [ 0.162992] ftrace: allocating 48736 entries in 192 pages164machine # [ 0.162994] ftrace: allocated 192 pages with 2 groups165machine # [ 0.163816] Dynamic Preempt: lazy166machine # [ 0.163971] rcu: Preemptible hierarchical RCU implementation.167machine # [ 0.163972] rcu: RCU event tracing is enabled.168machine # [ 0.163973] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=2.169machine # [ 0.163974] Trampoline variant of Tasks RCU enabled.170machine # [ 0.163975] Rude variant of Tasks RCU enabled.171machine # [ 0.163975] Tracing variant of Tasks RCU enabled.172machine # [ 0.163976] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.173machine # [ 0.163977] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2174machine # [ 0.163987] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.175machine # [ 0.163989] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.176machine # [ 0.163989] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.177machine # [ 0.168355] NR_IRQS: 24832, nr_irqs: 440, preallocated irqs: 16178machine # [ 0.168640] rcu: srcu_init: Setting srcu_struct sizes based on contention.179machine # [ 0.168648] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns180machine # [ 0.168750] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)181machine # [ 0.172332] Console: colour VGA+ 80x25182machine # [ 0.172335] printk: legacy console [tty0] enabled183machine # [ 0.204118] printk: legacy console [ttyS0] enabled184machine # [ 0.312996] ACPI: Core revision 20250807185machine # [ 0.313878] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns186machine # [ 0.315477] APIC: Switch to symmetric I/O mode setup187machine # [ 0.316537] x2apic enabled188machine # [ 0.317289] APIC: Switched APIC routing to: physical x2apic189machine # [ 0.318279] kvm-guest: APIC: send_IPI_mask() replaced with kvm_send_ipi_mask()190machine # [ 0.319584] kvm-guest: APIC: send_IPI_mask_allbutself() replaced with kvm_send_ipi_mask_allbutself()191machine # [ 0.321118] kvm-guest: setup PV IPIs192machine # [ 0.322721] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1193machine # [ 0.323778] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229842dd0bd, max_idle_ns: 440795319571 ns194machine # [ 0.327994] Calibrating delay loop (skipped) preset value.. 4800.02 BogoMIPS (lpj=2400012)195machine # [ 0.329078] x86/cpu: User Mode Instruction Prevention (UMIP) activated196machine # [ 0.331072] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127197machine # [ 0.331991] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0198machine # [ 0.332994] mitigations: Enabled attack vectors: user_kernel, user_user, guest_host, guest_guest, SMT mitigations: auto199machine # [ 0.333991] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl200machine # [ 0.335991] Transient Scheduler Attacks: Vulnerable: No microcode201machine # [ 0.336991] Spectre V2 : Mitigation: Enhanced / Automatic IBRS202machine # [ 0.337991] Speculative Return Stack Overflow: Mitigation: Safe RET203machine # [ 0.338991] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization204machine # [ 0.339998] Spectre V2 : Enabling IBPB for BPF205machine # [ 0.340992] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier206machine # [ 0.341992] active return thunk: srso_alias_return_thunk207machine # [ 0.343018] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'208machine # [ 0.343991] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'209machine # [ 0.345734] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'210machine # [ 0.346737] x86/fpu: Supporting XSAVE feature 0x020: 'AVX-512 opmask'211machine # [ 0.347768] x86/fpu: Supporting XSAVE feature 0x040: 'AVX-512 Hi256'212machine # [ 0.348740] x86/fpu: Supporting XSAVE feature 0x080: 'AVX-512 ZMM_Hi256'213machine # [ 0.349778] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'214machine # [ 0.350991] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256215machine # [ 0.351990] x86/fpu: xstate_offset[5]: 832, xstate_sizes[5]: 64216machine # [ 0.352991] x86/fpu: xstate_offset[6]: 896, xstate_sizes[6]: 512217machine # [ 0.353946] x86/fpu: xstate_offset[7]: 1408, xstate_sizes[7]: 1024218machine # [ 0.354991] x86/fpu: xstate_offset[9]: 2432, xstate_sizes[9]: 8219machine # [ 0.355991] x86/fpu: Enabled xstate features 0x2e7, context size is 2440 bytes, using 'compacted' format.220machine # [ 0.385720] Freeing SMP alternatives memory: 44K221machine # [ 0.386001] pid_max: default: 32768 minimum: 301222machine # [ 0.387084] LSM: initializing lsm=capability,landlock,yama,bpf,ima223machine # [ 0.388106] landlock: Up and running.224machine # [ 0.388992] Yama: becoming mindful.225machine # [ 0.390025] LSM support for eBPF active226machine # [ 0.390826] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)227machine # [ 0.392059] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)228machine # [ 0.394368] smpboot: CPU0: AMD EPYC 9654 96-Core Processor (family: 0x19, model: 0x11, stepping: 0x1)229machine # [ 0.395572] Performance Events: Fam17h+ core perfctr, AMD PMU driver.230machine # [ 0.396000] ... version: 2231machine # [ 0.396726] ... bit width: 48232machine # [ 0.396993] ... generic counters: 6233machine # [ 0.397686] ... generic bitmap: 000000000000003f234machine # [ 0.397993] ... fixed-purpose counters: 0235machine # [ 0.398718] ... fixed-purpose bitmap: 0000000000000000236machine # [ 0.398993] ... value mask: 0000ffffffffffff237machine # [ 0.399886] ... max period: 00007fffffffffff238machine # [ 0.400647] ... global_ctrl mask: 000000000000003f239machine # [ 0.401090] signal: max sigframe size: 3376240machine # [ 0.401894] rcu: Hierarchical SRCU implementation.241machine # [ 0.402589] rcu: Max phase no-delay instances is 400.242machine # [ 0.403166] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level243machine # [ 0.408429] smp: Bringing up secondary CPUs ...244machine # [ 0.409308] smpboot: x86: Booting SMP configuration:245machine # [ 0.410002] .... node #0, CPUs: #1246machine # [ 0.411105] smp: Brought up 1 node, 2 CPUs247machine # [ 0.412481] smpboot: Total of 2 processors activated (9600.04 BogoMIPS)248machine # [ 0.413299] Memory: 2928480K/3145176K available (17231K kernel code, 2726K rwdata, 13600K rodata, 3644K init, 2988K bss, 203680K reserved, 0K cma-reserved)249machine # [ 0.414998] devtmpfs: initialized250machine # [ 0.416108] x86/mm: Memory block size: 128MB251machine # [ 0.419060] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)252machine # [ 0.420035] futex hash table entries: 512 (32768 bytes on 1 NUMA nodes, total 32 KiB, linear).253machine # [ 0.421092] pinctrl core: initialized pinctrl subsystem254machine # [ 0.422232] PM: RTC time: 15:39:07, date: 2026-09-20255machine # [ 0.425844] NET: Registered PF_NETLINK/PF_ROUTE protocol family256machine # [ 0.427486] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations257machine # [ 0.428023] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations258machine # [ 0.429528] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations259machine # [ 0.430004] audit: initializing netlink subsys (disabled)260machine # [ 0.431039] audit: type=2000 audit(1789918748.027:1): state=initialized audit_enabled=0 res=1261machine # [ 0.431273] thermal_sys: Registered thermal governor 'fair_share'262machine # [ 0.431995] thermal_sys: Registered thermal governor 'bang_bang'263machine # [ 0.432965] thermal_sys: Registered thermal governor 'step_wise'264machine # [ 0.433734] thermal_sys: Registered thermal governor 'user_space'265machine # [ 0.433994] thermal_sys: Registered thermal governor 'power_allocator'266machine # [ 0.434997] cpuidle: using governor menu267machine # [ 0.437175] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5268machine # [ 0.438226] PCI: ECAM [mem 0xb0000000-0xbfffffff] (base 0xb0000000) for domain 0000 [bus 00-ff]269machine # [ 0.438997] PCI: ECAM [mem 0xb0000000-0xbfffffff] reserved as E820 entry270machine # [ 0.440006] PCI: Using configuration type 1 for base access271machine # [ 0.441149] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.272machine # [ 0.452078] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages273machine # [ 0.455014] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page274machine # [ 0.458000] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages275machine # [ 0.459998] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page276machine # [ 0.469721] ACPI: Added _OSI(Module Device)277machine # [ 0.471385] ACPI: Added _OSI(Processor Device)278machine # [ 0.473000] ACPI: Added _OSI(Processor Aggregator Device)279machine # [ 0.481702] ACPI: 1 ACPI AML tables successfully acquired and loaded280machine # [ 0.488039] ACPI: Interpreter enabled281machine # [ 0.489032] ACPI: PM: (supports S0 S3 S4 S5)282machine # [ 0.490999] ACPI: Using IOAPIC for interrupt routing283machine # [ 0.493114] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug284machine # [ 0.497001] PCI: Using E820 reservations for host bridge windows285machine # [ 0.499352] ACPI: Enabled 2 GPEs in block 00 to 3F286machine # [ 0.509081] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])287machine # [ 0.511004] acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]288machine # [ 0.514177] acpi PNP0A08:00: _OSC: platform does not support [PCIeHotplug LTR]289machine # [ 0.517296] acpi PNP0A08:00: _OSC: OS now controls [PME AER PCIeCapability]290machine # [ 0.519763] PCI host bridge to bus 0000:00291machine # [ 0.520555] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]292machine # [ 0.521994] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]293machine # [ 0.522994] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]294machine # [ 0.523993] pci_bus 0000:00: root bus resource [mem 0x80000000-0xafffffff window]295machine # [ 0.525993] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window]296machine # [ 0.526993] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe07ffffffff window]297machine # [ 0.527994] pci_bus 0000:00: root bus resource [bus 00-ff]298machine # [ 0.529083] pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000 conventional PCI endpoint299machine # [ 0.531436] pci 0000:00:01.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint300machine # [ 0.542078] pci 0000:00:01.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]301machine # [ 0.543005] pci 0000:00:01.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]302machine # [ 0.544048] pci 0000:00:01.0: ROM [mem 0xfebc0000-0xfebcffff pref]303machine # [ 0.546170] pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]304machine # [ 0.547701] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint305machine # [ 0.552032] pci 0000:00:02.0: BAR 0 [io 0xc100-0xc11f]306machine # [ 0.552957] pci 0000:00:02.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]307machine # [ 0.554016] pci 0000:00:02.0: BAR 4 [mem 0xe0000000000-0xe0000003fff 64bit pref]308machine # [ 0.555999] pci 0000:00:02.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]309machine # [ 0.557565] pci 0000:00:03.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint310machine # [ 0.561031] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]311machine # [ 0.562013] pci 0000:00:03.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]312machine # [ 0.563016] pci 0000:00:03.0: BAR 4 [mem 0xe0000004000-0xe0000007fff 64bit pref]313machine # [ 0.564546] pci 0000:00:04.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint314machine # [ 0.567963] pci 0000:00:04.0: BAR 0 [io 0xc000-0xc07f]315machine # [ 0.569717] pci 0000:00:04.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]316machine # [ 0.570016] pci 0000:00:04.0: BAR 4 [mem 0xe0000008000-0xe000000bfff 64bit pref]317machine # [ 0.572551] pci 0000:00:05.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint318machine # [ 0.577032] pci 0000:00:05.0: BAR 0 [io 0xc140-0xc15f]319machine # [ 0.577943] pci 0000:00:05.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]320machine # [ 0.578802] pci 0000:00:05.0: BAR 4 [mem 0xe000000c000-0xe000000ffff 64bit pref]321machine # [ 0.579970] pci 0000:00:05.0: ROM [mem 0xfeb80000-0xfebbffff pref]322machine # [ 0.581386] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint323machine # [ 0.584006] pci 0000:00:06.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]324machine # [ 0.585004] pci 0000:00:06.0: BAR 4 [mem 0xe0000010000-0xe0000013fff 64bit pref]325machine # [ 0.587586] pci 0000:00:07.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint326machine # [ 0.590006] pci 0000:00:07.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]327machine # [ 0.591004] pci 0000:00:07.0: BAR 4 [mem 0xe0000014000-0xe0000017fff 64bit pref]328machine # [ 0.592579] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint329machine # [ 0.595039] pci 0000:00:08.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]330machine # [ 0.608020] pci 0000:00:08.0: BAR 4 [mem 0xe0000018000-0xe000001bfff 64bit pref]331machine # [ 0.610783] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint332machine # [ 0.613910] pci 0000:00:09.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]333machine # [ 0.614767] pci 0000:00:09.0: BAR 4 [mem 0xe000001c000-0xe000001ffff 64bit pref]334machine # [ 0.616551] pci 0000:00:0a.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint335machine # [ 0.621042] pci 0000:00:0a.0: BAR 0 [io 0xc080-0xc0bf]336machine # [ 0.621935] pci 0000:00:0a.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]337machine # [ 0.623050] pci 0000:00:0a.0: BAR 4 [mem 0xe0000020000-0xe0000023fff 64bit pref]338machine # [ 0.625578] pci 0000:00:0b.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint339machine # [ 0.628031] pci 0000:00:0b.0: BAR 0 [io 0xc160-0xc17f]340machine # [ 0.628946] pci 0000:00:0b.0: BAR 1 [mem 0xfebda000-0xfebdafff]341machine # [ 0.630805] pci 0000:00:0b.0: BAR 4 [mem 0xe0000024000-0xe0000027fff 64bit pref]342machine # [ 0.632564] pci 0000:00:1d.0: [8086:2934] type 00 class 0x0c0300 conventional PCI endpoint343machine # [ 0.634725] pci 0000:00:1d.0: BAR 4 [io 0xc180-0xc19f]344machine # [ 0.636191] pci 0000:00:1d.1: [8086:2935] type 00 class 0x0c0300 conventional PCI endpoint345machine # [ 0.638705] pci 0000:00:1d.1: BAR 4 [io 0xc1a0-0xc1bf]346machine # [ 0.639192] pci 0000:00:1d.2: [8086:2936] type 00 class 0x0c0300 conventional PCI endpoint347machine # [ 0.641771] pci 0000:00:1d.2: BAR 4 [io 0xc1c0-0xc1df]348machine # [ 0.642242] pci 0000:00:1d.7: [8086:293a] type 00 class 0x0c0320 conventional PCI endpoint349machine # [ 0.645682] pci 0000:00:1d.7: BAR 0 [mem 0xfebdb000-0xfebdbfff]350machine # [ 0.646283] pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100 conventional PCI endpoint351machine # [ 0.648285] pci 0000:00:1f.0: quirk: [io 0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO352machine # [ 0.650249] pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601 conventional PCI endpoint353machine # [ 0.652022] pci 0000:00:1f.2: BAR 4 [io 0xc1e0-0xc1ff]354machine # [ 0.652913] pci 0000:00:1f.2: BAR 5 [mem 0xfebdc000-0xfebdcfff]355machine # [ 0.655507] pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500 conventional PCI endpoint356machine # [ 0.657653] pci 0000:00:1f.3: BAR 4 [io 0x0700-0x073f]357machine # [ 0.661059] ACPI: PCI: Interrupt link LNKA configured for IRQ 10358machine # [ 0.662105] ACPI: PCI: Interrupt link LNKB configured for IRQ 10359machine # [ 0.663093] ACPI: PCI: Interrupt link LNKC configured for IRQ 11360machine # [ 0.664094] ACPI: PCI: Interrupt link LNKD configured for IRQ 11361machine # [ 0.666096] ACPI: PCI: Interrupt link LNKE configured for IRQ 10362machine # [ 0.667094] ACPI: PCI: Interrupt link LNKF configured for IRQ 10363machine # [ 0.668092] ACPI: PCI: Interrupt link LNKG configured for IRQ 11364machine # [ 0.669111] ACPI: PCI: Interrupt link LNKH configured for IRQ 11365machine # [ 0.670030] ACPI: PCI: Interrupt link GSIA configured for IRQ 16366machine # [ 0.671011] ACPI: PCI: Interrupt link GSIB configured for IRQ 17367machine # [ 0.672006] ACPI: PCI: Interrupt link GSIC configured for IRQ 18368machine # [ 0.673006] ACPI: PCI: Interrupt link GSID configured for IRQ 19369machine # [ 0.674006] ACPI: PCI: Interrupt link GSIE configured for IRQ 20370machine # [ 0.675006] ACPI: PCI: Interrupt link GSIF configured for IRQ 21371machine # [ 0.676008] ACPI: PCI: Interrupt link GSIG configured for IRQ 22372machine # [ 0.677008] ACPI: PCI: Interrupt link GSIH configured for IRQ 23373machine # [ 0.680148] iommu: Default domain type: Translated374machine # [ 0.681023] iommu: DMA domain TLB invalidation policy: lazy mode375machine # [ 0.682209] ACPI: bus type USB registered376machine # [ 0.683056] usbcore: registered new interface driver usbfs377machine # [ 0.684003] usbcore: registered new interface driver hub378machine # [ 0.685003] usbcore: registered new device driver usb379machine # [ 0.687124] NetLabel: Initializing380machine # [ 0.687758] NetLabel: domain hash size = 128381machine # [ 0.687994] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO382machine # [ 0.689077] NetLabel: unlabeled traffic allowed by default383machine # [ 0.690004] PCI: Using ACPI for IRQ routing384machine # [ 0.734152] pci 0000:00:01.0: vgaarb: setting as boot VGA device385machine # [ 0.734990] pci 0000:00:01.0: vgaarb: bridge control possible386machine # [ 0.734990] pci 0000:00:01.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none387machine # [ 0.737000] vgaarb: loaded388machine # [ 0.737738] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0389machine # [ 0.738994] hpet0: 3 comparators, 64-bit 100.000000 MHz counter390machine # [ 0.744078] clocksource: Switched to clocksource kvm-clock391machine # [ 0.745752] VFS: Disk quotas dquot_6.6.0392machine # [ 0.746480] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)393machine # [ 0.749477] pnp: PnP ACPI init394machine # [ 0.751195] ACPI: IRQ 4 override to edge(!), high(!)395machine # [ 0.752259] system 00:04: [mem 0xb0000000-0xbfffffff window] has been reserved396machine # [ 0.753907] pnp: PnP ACPI: found 5 devices397machine # [ 0.762064] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns398machine # [ 0.763656] clocksource: Switched to clocksource acpi_pm399machine # [ 0.764674] NET: Registered PF_INET protocol family400machine # [ 0.766111] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)401machine # [ 0.782993] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)402machine # [ 0.784500] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)403machine # [ 0.785917] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)404machine # [ 0.787396] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)405machine # [ 0.788760] TCP: Hash tables configured (established 32768 bind 32768)406machine # [ 0.790123] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear)407machine # [ 0.791593] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)408machine # [ 0.792868] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)409machine # [ 0.794208] NET: Registered PF_UNIX/PF_LOCAL protocol family410machine # [ 0.795199] NET: Registered PF_XDP protocol family411machine # [ 0.796072] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]412machine # [ 0.797129] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]413machine # [ 0.798174] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]414machine # [ 0.799313] pci_bus 0000:00: resource 7 [mem 0x80000000-0xafffffff window]415machine # [ 0.800474] pci_bus 0000:00: resource 8 [mem 0xc0000000-0xfebfffff window]416machine # [ 0.801618] pci_bus 0000:00: resource 9 [mem 0xe0000000000-0xe07ffffffff window]417machine # [ 0.803501] ACPI: \_SB_.GSIA: Enabled at IRQ 16418machine # [ 0.805574] ACPI: \_SB_.GSIB: Enabled at IRQ 17419machine # [ 0.807568] ACPI: \_SB_.GSIC: Enabled at IRQ 18420machine # [ 0.809557] ACPI: \_SB_.GSID: Enabled at IRQ 19421machine # [ 0.811400] PCI: CLS 0 bytes, default 64422machine # [ 0.812241] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)423machine # [ 0.812573] Trying to unpack rootfs image as initramfs...424machine # [ 0.813408] software IO TLB: mapped [mem 0x000000007a36d000-0x000000007e36d000] (64MB)425machine # [ 0.813524] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229842dd0bd, max_idle_ns: 440795319571 ns426machine # [ 0.836487] Initialise system trusted keyrings427machine # [ 0.839132] workingset: timestamp_bits=40 max_order=20 bucket_order=0428machine # [ 0.850502] Key type asymmetric registered429machine # [ 0.851230] Asymmetric key parser 'x509' registered430machine # [ 0.852132] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)431machine # [ 0.854431] io scheduler mq-deadline registered432machine # [ 0.855227] io scheduler kyber registered433machine # [ 0.857827] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled434machine # [ 0.859184] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A435machine # [ 0.861330] Linux agpgart interface v0.103436machine # [ 0.862168] ACPI: bus type drm_connector registered437machine # [ 0.866318] usbcore: registered new interface driver usbserial_generic438machine # [ 0.867605] usbserial: USB Serial support registered for generic439machine # [ 0.869547] amd_pstate: The CPPC feature is supported but currently disabled by the BIOS.440machine # [ 0.869547] Please enable it if your BIOS has the CPPC option.441machine # [ 0.874052] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled442machine # [ 0.876885] drop_monitor: Initializing network drop monitor service443machine # [ 0.879434] NET: Registered PF_INET6 protocol family444machine # [ 0.882496] Segment Routing with IPv6445machine # [ 0.883863] In-situ OAM (IOAM) with IPv6446machine # [ 0.886785] IPI shorthand broadcast: enabled447machine # [ 0.893454] sched_clock: Marking stable (743011109, 150342654)->(912234898, -18881135)448machine # [ 0.895201] registered taskstats version 1449machine # [ 0.896214] Loading compiled-in X.509 certificates450machine # [ 0.905988] Demotion targets for Node 0: null451machine # [ 0.907427] Key type .fscrypt registered452machine # [ 0.908156] Key type fscrypt-provisioning registered453machine # [ 0.909168] ima: No TPM chip found, activating TPM-bypass!454machine # [ 0.910164] ima: Allocated hash algorithm: sha1455machine # [ 0.911047] ima: No architecture policies found456machine # [ 0.912102] PM: Magic number: 10:246:690457machine # [ 0.912901] mem mem: hash matches458machine # [ 0.914440] RAS: Correctable Errors collector initialized.459machine # [ 0.918864] clk: Disabling unused clocks460machine # [ 0.919589] PM: genpd: Disabling unused power domains461machine # [ 1.093235] Freeing initrd memory: 29068K462machine # [ 1.100548] Freeing unused decrypted memory: 2028K463machine # [ 1.106938] Freeing unused kernel image (initmem) memory: 3644K464machine # [ 1.109687] Write protecting the kernel read-only data: 32768k465machine # [ 1.114594] Freeing unused kernel image (text/rodata gap) memory: 1200K466machine # [ 1.118428] Freeing unused kernel image (rodata/data gap) memory: 736K467machine # [ 1.171734] x86/mm: Checked W+X mappings: passed, no W+X pages found.468machine # [ 1.172969] Run /init as init process469machine # [ 1.184898] systemd[1]: Inserted module 'autofs4'470machine # [ 1.210056] fuse: init (API version 7.45)471machine # [ 1.218822] ACPI: \_SB_.GSIG: Enabled at IRQ 22472machine # [ 1.221480] ACPI: \_SB_.GSIH: Enabled at IRQ 23473machine # [ 1.225767] ACPI: \_SB_.GSIE: Enabled at IRQ 20474machine # [ 1.231024] ACPI: \_SB_.GSIF: Enabled at IRQ 21475machine # [ 1.243794] virtiofs virtio5: discovered new tag: nix-store476machine # [ 1.248238] virtiofs virtio5: virtio_fs_setup_dax: No cache capability477machine # [ 1.285128] virtiofs virtio6: discovered new tag: shared478machine # [ 1.288178] virtiofs virtio6: virtio_fs_setup_dax: No cache capability479machine # [ 1.294471] virtiofs virtio7: discovered new tag: xchg480machine # [ 1.296098] virtiofs virtio7: virtio_fs_setup_dax: No cache capability481machine # [ 1.318889] systemd[1]: Successfully made /usr/ read-only.482machine # [ 1.655626] 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)483machine # [ 1.668084] systemd[1]: Detected virtualization kvm.484machine # [ 1.670335] systemd[1]: Detected architecture x86-64.485machine # [ 1.672541] systemd[1]: Running in initrd.486machine # [ 1.675044] systemd[1]: Initializing machine ID from random generator.487machine # [ 1.678086] systemd[1]: Hostname set to <machine>.488machine # [ 1.802843] systemd[1]: bpf-restrict-fs: LSM BPF program attached489machine # [ 1.840819] systemd[1]: Queued start job for default target Initrd Default Target.490machine # [ 1.850334] systemd[1]: Created slice Slice /system/modprobe.491machine # [ 1.853246] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.492machine # [ 1.856727] systemd[1]: Expecting device /dev/disk/by-label/nixos...493machine # [ 1.859425] systemd[1]: Reached target Path Units.494machine # [ 1.861513] systemd[1]: Reached target Slice Units.495machine # [ 1.863651] systemd[1]: Reached target Swaps.496machine # [ 1.865581] systemd[1]: Reached target Timer Units.497machine # [ 1.867894] systemd[1]: Listening on D-Bus System Message Bus Socket.498machine # [ 1.870842] systemd[1]: Listening on Journal Socket (/dev/log).499machine # [ 1.873672] systemd[1]: Listening on Journal Sockets.500machine # [ 1.876054] systemd[1]: Listening on udev Control Socket.501machine # [ 1.878707] systemd[1]: Listening on udev Kernel Socket.502machine # [ 1.881025] systemd[1]: Reached target Socket Units.503machine # [ 1.885300] systemd[1]: Starting Create List of Static Device Nodes...504machine # [ 1.898437] systemd[1]: Starting Load Kernel Module configfs...505machine # [ 1.906440] systemd[1]: Starting Journal Service...506machine # [ 1.909077] systemd[1]: Starting Load Kernel Modules...507machine # [ 1.911482] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os508machine # [ 1.930552] systemd[1]: Starting Coldplug All udev Devices...509machine # [ 1.947357] systemd[1]: Finished Create List of Static Device Nodes.510machine # [ 1.949035] systemd[1]: modprobe@configfs.service: Deactivated successfully.511machine # [ 1.953482] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.512machine # [ 1.956717] systemd[1]: Finished Load Kernel Module configfs.513machine # [ 1.958105] systemd[1]: Kernel Configuration File System skipped, unmet condition check ConditionPathExists=/sys/kernel/config514machine # [ 1.959044] systemd-journald[74]: Collecting audit messages is disabled.515machine # [ 1.961234] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev516machine # [ 1.964175] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...517machine # [ 1.972412] systemd[1]: Finished Load Kernel Modules.518machine # [ 1.977443] systemd[1]: Starting Apply Kernel Variables...519machine # [ 1.995501] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.520machine # [ 2.000623] systemd[1]: Starting Create Static Device Nodes in /dev...521machine # [ 1.856868] systemd-modules-load[75]: Using 2[ 2.007555] systemd[1]: Started Journal Service.522machine # probe threads523machine # [ 1.858779] systemd-modules-load[75]: Inserted module 'virtio_balloon'524machine # [ 1.859858] systemd-modules-load[75]: Inserted module 'virtio_gpu'525machine # [ 1.860862] systemd-modules-load[75]: Inserted module 'dm_mod'526machine # [ 1.863287] systemd[1]: Finished Apply Kernel Variables.527machine # [ 1.873903] systemd[1]: Finished Create Static Device Nodes in /dev.528machine # [ 1.875399] systemd[1]: Reached target Preparation for Local File Systems.529machine # [ 1.876634] systemd[1]: Reached target Local File Systems.530machine # [ 1.879139] systemd[1]: Starting Create System Files and Directories...531machine # [ 1.882182] systemd[1]: Starting Rule-based Manager for Device Events and Files...532machine # [ 1.899796] systemd[1]: Finished Create System Files and Directories.533machine # [ 1.907988] systemd-udevd[92]: Using default interface naming scheme 'v261'.534machine # [ 1.920830] systemd[1]: Started Rule-based Manager for Device Events and Files.535machine # [ 1.937023] systemd[1]: Finished Coldplug All udev Devices.536machine # [ 1.937837] systemd[1]: Reached target System Initialization.537machine # [ 1.938596] systemd[1]: Reached target Basic System.538machine # [ 2.213716] uhci_hcd 0000:00:1d.0: UHCI Host Controller539machine # [ 2.215225] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 1540machine # [ 2.216265] uhci_hcd 0000:00:1d.0: detected 2 ports541machine # [ 2.222395] uhci_hcd 0000:00:1d.0: irq 16, io port 0x0000c180542machine # [ 2.227121] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18543machine # [ 2.228460] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1544machine # [ 2.230386] usb usb1: Product: UHCI Host Controller545machine # [ 2.231060] usb usb1: Manufacturer: Linux 6.18.51 uhci_hcd546machine # [ 2.233943] usb usb1: SerialNumber: 0000:00:1d.0547machine # [ 2.235201] SCSI subsystem initialized548machine # [ 2.256861] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12549machine # [ 2.112890] (udev-worker)[105]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.550machine # [ 2.114916] (udev-worker)[105]: Network interface NamePolicy= disabled on kernel command line.551machine # [ 2.116275] (udev-worker)[107]: Network interface NamePolicy= disabled on kernel command line.552machine # [ 2.270136] serio: i8042 KBD port at 0x60,0x64 irq 1553machine # [ 2.270898] serio: i8042 AUX port at 0x60,0x64 irq 12554machine # [ 2.277748] virtio_blk virtio2: 2/0/0 default/read/poll queues555machine # [ 2.281774] virtio_blk virtio2: [vda] 16777216 512-byte logical blocks (8.59 GB/8.00 GiB)556machine # [ 2.135069] systemd[1]: Starting Virtual Console Setup...557machine # [ 2.287700] hub 1-0:1.0: USB hub found558machine # [ 2.289911] hub 1-0:1.0: 2 ports detected559machine # [ 2.292422] ehci-pci 0000:00:1d.7: EHCI Host Controller560machine # [ 2.293790] ehci-pci 0000:00:1d.7: new USB bus registered, assigned bus number 2561machine # [ 2.295033] ehci-pci 0000:00:1d.7: irq 19, io mem 0xfebdb000562machine # [ 2.301383] ehci-pci 0000:00:1d.7: USB 2.0 started, EHCI 1.00563machine # [ 2.302221] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.18564machine # [ 2.303407] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1565machine # [ 2.303410] usb usb2: Product: EHCI Host Controller566machine # [ 2.303412] usb usb2: Manufacturer: Linux 6.18.51 ehci_hcd567machine # [ 2.303413] usb usb2: SerialNumber: 0000:00:1d.7568machine # [ 2.306695] hub 2-0:1.0: USB hub found569machine # [ 2.308372] hub 2-0:1.0: 6 ports detected570machine # [ 2.163341] systemd-vconsole-setup[120]: Configuration of first virtual console was skipped, ignoring remaining ones.571machine # [ 2.165449] systemd[1]: Finished Virtual Console Setup.572machine # [ 2.329469] hub 1-0:1.0: USB hub found573machine # [ 2.330046] hub 1-0:1.0: 2 ports detected574machine # [ 2.331457] uhci_hcd 0000:00:1d.1: UHCI Host Controller575machine # [ 2.332177] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3576machine # [ 2.333218] uhci_hcd 0000:00:1d.1: detected 2 ports577machine # [ 2.334017] uhci_hcd 0000:00:1d.1: irq 17, io port 0x0000c1a0578machine # [ 2.338041] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0579machine # [ 2.341964] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18580machine # [ 2.344275] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1581machine # [ 2.345527] usb usb3: Product: UHCI Host Controller582machine # [ 2.346225] usb usb3: Manufacturer: Linux 6.18.51 uhci_hcd583machine # [ 2.347181] usb usb3: SerialNumber: 0000:00:1d.1584machine # [ 2.348041] hub 3-0:1.0: USB hub found585machine # [ 2.348909] hub 3-0:1.0: 2 ports detected586machine # [ 2.352308] uhci_hcd 0000:00:1d.2: UHCI Host Controller587machine # [ 2.353227] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4588machine # [ 2.355750] uhci_hcd 0000:00:1d.2: detected 2 ports589machine # [ 2.356844] uhci_hcd 0000:00:1d.2: irq 18, io port 0x0000c1c0590machine # [ 2.358544] usb usb4: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18591machine # [ 2.359815] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1592machine # [ 2.210543] systemd[1]: Found device /dev/disk/by-label/nixos.593machine # [ 2.211738] systemd[1]: Reached target Initrd Root Device.594machine # [ 2.364046] usb usb4: Product: UHCI Host Controller595machine # [ 2.364825] usb usb4: Manufacturer: Linux 6.18.51 uhci_hcd596machine # [ 2.215116] systemd[1]: Starting File System [ 2.365660] usb usb4: SerialNumber: 0000:00:1d.2597machine # Check on /dev/disk/by-label/nixos...598machine # [ 2.366942] hub 4-0:1.0: USB hub found599machine # [ 2.367704] hub 4-0:1.0: 2 ports detected600machine # [ 2.240371] systemd-fsck[128]: nixos: clean, 12/524288 files, 58513/2097152 blocks601machine # [ 2.245803] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.602machine # [ 2.397565] ahci 0000:00:1f.2: AHCI vers 0001.0000, 32 command slots, 1.5 Gbps, SATA mode603machine # [ 2.398856] ahci 0000:00:1f.2: 6/6 ports implemented (port mask 0x3f)604machine # [ 2.399970] ahci 0000:00:1f.2: flags: 64bit ncq only605machine # [ 2.402273] scsi host0: ahci606machine # [ 2.403327] scsi host1: ahci607machine # [ 2.404664] scsi host2: ahci608machine # [ 2.405791] scsi host3: ahci609machine # [ 2.406833] scsi host4: ahci610machine # [ 2.408271] scsi host5: ahci611machine # [ 2.409102] ata1: SATA max UDMA/133 abar m4096@0xfebdc000 port 0xfebdc100 irq 48 lpm-pol 1612machine # [ 2.411417] ata2: SATA max UDMA/133 abar m4096@0xfebdc000 port 0xfebdc180 irq 48 lpm-pol 1613machine # [ 2.412816] ata3: SATA max UDMA/133 abar m4096@0xfebdc000 port 0xfebdc200 irq 48 lpm-pol 1614machine # [ 2.414151] ata4: SATA max UDMA/133 abar m4096@0xfebdc000 port 0xfebdc280 irq 48 lpm-pol 1615machine # [ 2.415402] ata5: SATA max UDMA/133 abar m4096@0xfebdc000 port 0xfebdc300 irq 48 lpm-pol 1616machine # [ 2.416635] ata6: SATA max UDMA/133 abar m4096@0xfebdc000 port 0xfebdc380 irq 48 lpm-pol 1617machine # [ 2.543538] usb 2-1: new high-speed USB device number 2 using ehci-pci618machine # [ 2.673573] usb 2-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00619machine # [ 2.676449] usb 2-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10620machine # [ 2.679025] usb 2-1: Product: QEMU USB Tablet621machine # [ 2.680648] usb 2-1: Manufacturer: QEMU622machine # [ 2.682065] usb 2-1: SerialNumber: 28754-0000:00:1d.7-1623machine # [ 2.702604] hid: raw HID events driver (C) Jiri Kosina624machine # [ 2.733834] ata5: SATA link down (SStatus 0 SControl 300)625machine # [ 2.734824] ata2: SATA link down (SStatus 0 SControl 300)626machine # [ 2.737030] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300)627machine # [ 2.738203] ata6: SATA link down (SStatus 0 SControl 300)628machine # [ 2.740313] ata1: SATA link down (SStatus 0 SControl 300)629machine # [ 2.741393] ata4: SATA link down (SStatus 0 SControl 300)630machine # [ 2.743456] ata3.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100631machine # [ 2.745382] ata3.00: applying bridge limits632machine # [ 2.747033] ata3.00: configured for UDMA/100633machine # [ 2.749238] scsi 2:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5634machine # [ 2.771469] usbcore: registered new interface driver usbhid635machine # [ 2.772220] usbhid: USB HID core driver636machine # [ 2.788629] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0/0003:0627:0001.0001/input/input2637machine # [ 2.793924] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:1d.7-1/input0638machine # [ 2.808506] sr 2:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray639machine # [ 2.842460] cdrom: Uniform CD-ROM driver Revision: 3.20640machine # [ 2.792483] systemd[1]: Mounting /sysroot...641machine # [ 3.058070] EXT4-fs (vda): mounted filesystem 9bb956bf-81dc-4ac2-b27d-c9d678fa930a r/w with ordered data mode. Quota mode: none.642machine # [ 2.911479] systemd[1]: Mounted /sysroot.643machine # [ 2.913575] systemd[1]: Reached target Initrd Root File System.644machine # [ 2.920383] systemd[1]: Mounting /sysroot/nix/.ro-store...645machine # [ 2.923190] systemd[1]: Mounting /sysroot/nix/.rw-store...646machine # [ 2.927128] systemd[1]: Mounting /sysroot/run...647machine # [ 2.932240] systemd[1]: Mounting /sysroot/tmp/shared...648machine # [ 2.938260] systemd[1]: Mounting /sysroot/tmp/xchg...649machine # [ 2.945762] systemd[1]: Starting Mountpoints Configured in the Real Root...650machine # [ 2.951524] systemd[1]: Mounted /sysroot/nix/.ro-store.651machine # [ 2.953793] systemd[1]: Mounted /sysroot/nix/.rw-store.652machine # [ 2.954881] systemd[1]: Mounted /sysroot/run.653machine # [ 2.956439] systemd-sysroot-fstab-check[170]: /sysroot should be mounted in the initrd, will request daemon-reload.654machine # [ 2.957869] systemd[1]: Mounted /sysroot/tmp/shared.655machine # [ 2.958934] systemd[1]: Mounted /sysroot/tmp/xchg.656machine # [ 2.963158] systemd[1]: Starting rw-sysroot-nix-store.service...657machine # [ 2.964085] systemd[1]: Reload requested from client PID 170 ('systemd-sysroot') (unit initrd-parse-etc.service)...658machine # [ 2.965570] systemd[1]: Reloading...659machine # [ 3.021254] systemd[1]: Reloading finished in 58 ms.660machine # [ 3.041905] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.661machine # [ 3.044601] systemd[1]: Finished rw-sysroot-nix-store.service.662machine # [ 3.046780] systemd[1]: Mounting /sysroot/nix/store...663machine # [ 3.048959] systemd-sysroot-fstab-check[170]: Requesting initrd-fs.target/start/replace...664machine # [ 3.053092] systemd-sysroot-fstab-check[170]: Requesting swap.target/start/replace...665machine # [ 3.058151] systemd[1]: initrd-parse-etc.service: Deactivated successfully.666machine # [ 3.061160] systemd[1]: Finished Mountpoints Configured in the Real Root.667machine # [ 3.064434] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.668machine # [ 3.070313] systemd[1]: Mounted /sysroot/nix/store.669machine # [ 3.072663] systemd[1]: Reached target Initrd File Systems.670machine # [ 3.075572] systemd[1]: Starting Find NixOS closure...671machine # [ 3.077517] systemd[1]: Starting rw-sysroot-nix-store.service...672machine # [ 3.085068] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...673machine # [ 3.087110] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.674machine # [ 3.088162] systemd[1]: Finished rw-sysroot-nix-store.service.675machine # [ 3.097481] systemd[1]: Finished Find NixOS closure.676machine # [ 3.102160] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.677machine # [ 3.103297] systemd[1]: Reached target Initrd Default Target.678machine # [ 3.104108] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...679machine # [ 3.121380] systemd[1]: Stopped target Initrd Default Target.680machine # [ 3.122244] systemd[1]: Stopped target Basic System.681machine # [ 3.122976] systemd[1]: Stopped target Initrd Root Device.682machine # [ 3.123773] systemd[1]: Stopped target Path Units.683machine # [ 3.124510] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.684machine # [ 3.125534] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.685machine # [ 3.126606] systemd[1]: Stopped target Slice Units.686machine # [ 3.127407] systemd[1]: Stopped target Socket Units.687machine # [ 3.130836] systemd[1]: Stopped target System Initialization.688machine # [ 3.131679] systemd[1]: Stopped target Swaps.689machine # [ 3.132374] systemd[1]: Stopped target Timer Units.690machine # [ 3.133087] systemd[1]: dbus.socket: Deactivated successfully.691machine # [ 3.133974] systemd[1]: Closed D-Bus System Message Bus Socket.692machine # [ 3.134978] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.693machine # [ 3.136038] systemd[1]: Stopped Find NixOS closure.694machine # [ 3.138708] systemd[1]: Starting rw-sysroot-nix-store.service...695machine # [ 3.139692] systemd[1]: systemd-sysctl.service: Deactivated successfully.696machine # [ 3.142067] systemd[1]: Stopped Apply Kernel Variables.697machine # [ 3.142829] systemd[1]: systemd-modules-load.service: Deactivated successfully.698machine # [ 3.143953] systemd[1]: Stopped Load Kernel Modules.699machine # [ 3.144684] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.700machine # [ 3.145764] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.701machine # [ 3.146896] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.702machine # [ 3.147949] systemd[1]: Stopped Create System Files and Directories.703machine # [ 3.148901] systemd[1]: Stopped target Local File Systems.704machine # [ 3.149727] systemd[1]: Stopped target Preparation for Local File Systems.705machine # [ 3.150700] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.706machine # [ 3.151698] systemd[1]: Stopped Coldplug All udev Devices.707machine # [ 3.152555] systemd[1]: Stopping Rule-based Manager for Device Events and Files...708machine # [ 3.153566] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.709machine # [ 3.154591] systemd[1]: Stopped Virtual Console Setup.710machine # [ 3.155374] systemd[1]: initrd-cleanup.service: Deactivated successfully.711machine # [ 3.156499] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.712machine # [ 3.157421] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.713machine # [ 3.158415] systemd[1]: Finished rw-sysroot-nix-store.service.714machine # [ 3.159218] systemd[1]: systemd-udevd.service: Deactivated successfully.715machine # [ 3.160158] systemd[1]: Stopped Rule-based Manager for Device Events and Files.716machine # [ 3.161178] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.717machine # [ 3.162171] systemd[1]: Closed udev Control Socket.718machine # [ 3.162890] systemd[1]: Starting Cleanup udev Database...719machine # [ 3.163688] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.720machine # [ 3.165022] systemd[1]: Stopped Create Static Device Nodes in /dev.721machine # [ 3.165979] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.722machine # [ 3.167118] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.723machine # [ 3.168189] systemd[1]: kmod-static-nodes.service: Deactivated successfully.724machine # [ 3.169175] systemd[1]: Stopped Create List of Static Device Nodes.725machine # [ 3.170122] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.726machine # [ 3.171157] systemd[1]: Finished Cleanup udev Database.727machine # [ 3.171865] systemd[1]: Reached target Switch Root.728machine # [ 3.172544] systemd[1]: Starting NixOS Activation...729machine # [ 3.243634] initrd-nixos-activation-start[215]: booting system configuration /nix/store/wmj0aysya0djq9bq63k8kccvmvzzgmv8-nixos-system-machine-test730machine # [ 3.271892] initrd-nixos-activation-start[215]: running activation script...731machine # [ 3.489515] initrd-nixos-activation-start[238]: setting up /etc...732machine # [ 3.609477] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.733machine # [ 3.610734] systemd[1]: Finished NixOS Activation.734machine # [ 3.612495] systemd[1]: Starting Switch Root...735machine # [ 3.630487] systemd[1]: Switching root.736machine # [ 3.829365] systemd-journald[74]: Received SIGTERM from PID 1 (systemd).737machine # [ 3.934491] NET: Registered PF_VSOCK protocol family738machine # [ 4.304713] 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)739machine # [ 4.319902] systemd[1]: Detected virtualization kvm.740machine # [ 4.320624] systemd[1]: Detected architecture x86-64.741machine # [ 4.321390] systemd[1]: Detected first boot.742machine # [ 4.323923] systemd[1]: Initializing machine ID from random generator.743machine # [ 4.435863] systemd[1]: bpf-restrict-fs: LSM BPF program attached744machine # [ 4.525127] systemd[1]: Applying preset policy.745machine # [ 4.687504] systemd[1]: Populated /etc with preset unit settings.746machine # [ 4.908728] systemd[1]: initrd-switch-root.service: Deactivated successfully.747machine # [ 4.910106] systemd[1]: Stopped initrd-switch-root.service.748machine # [ 4.912046] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.749machine # [ 4.914447] systemd[1]: Created slice Slice /system/getty.750machine # [ 4.915797] systemd[1]: Created slice User and Session Slice.751machine # [ 4.916730] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.752machine # [ 4.917924] systemd[1]: Started Forward Password Requests to Wall Directory Watch.753machine # [ 4.919024] systemd[1]: Expecting device /dev/hvc0...754machine # [ 4.919773] systemd[1]: Expecting device /dev/ttyS0...755machine # [ 4.920502] systemd[1]: Reached target Local Encrypted Volumes.756machine # [ 4.921288] systemd[1]: Stopped target initrd-fs.target.757machine # [ 4.922057] systemd[1]: Stopped target initrd-root-fs.target.758machine # [ 4.922879] systemd[1]: Stopped target initrd-switch-root.target.759machine # [ 4.923773] systemd[1]: Reached target Virtual Machines and Containers.760machine # [ 4.924721] systemd[1]: Reached target Path Units.761machine # [ 4.925428] systemd[1]: Reached target Remote File Systems.762machine # [ 4.926177] systemd[1]: Reached target Slice Units.763machine # [ 4.926929] systemd[1]: Reached target Swaps.764machine # [ 4.928755] systemd[1]: Listening on Query the User Interactively for a Password.765machine # [ 4.931219] systemd[1]: Listening on Process Core Dump Socket.766machine # [ 4.932998] systemd[1]: Listening on Credential Encryption/Decryption.767machine # [ 4.934925] systemd[1]: Listening on Factory Reset Management.768machine # [ 4.935870] systemd[1]: Listening on Hostname Service Socket.769machine # [ 4.938880] systemd[1]: Starting Journal Log Access Socket...770machine # [ 4.940162] systemd[1]: Listening on Journal Audit Socket.771machine # [ 4.942178] systemd[1]: Listening on Console Output Muting Service Socket.772machine # [ 4.943359] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.773machine # [ 4.944475] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os774machine # [ 4.945777] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki775machine # [ 4.949459] systemd[1]: Listening on Disk Repartitioning Service Socket.776machine # [ 4.950456] systemd[1]: Listening on udev Control Socket.777machine # [ 4.951289] systemd[1]: Listening on udev Varlink Socket.778machine # [ 4.953689] systemd[1]: Mounting Huge Pages File System...779machine # [ 4.955723] systemd[1]: Mounting POSIX Message Queue File System...780machine # [ 4.958056] systemd[1]: Mounting Kernel Debug File System...781machine # [ 4.963401] systemd[1]: Mounting Kernel Trace File System...782machine # [ 4.967502] systemd[1]: Starting Create List of Static Device Nodes...783machine # [ 4.973044] systemd[1]: Starting Load Kernel Module configfs...784machine # [ 4.973987] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm785machine # [ 4.976269] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore786machine # [ 4.980445] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse787machine # [ 4.987840] systemd[1]: Mounting FUSE Control File System...788machine # [ 4.989627] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67789machine # [ 4.997879] systemd[1]: Starting Journal Service...790machine # [ 5.000439] systemd[1]: Starting Load Kernel Modules...791machine # [ 5.004915] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...792machine # [ 5.009419] systemd[1]: Starting Remount Root and Kernel File Systems...793machine # [ 5.010408] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os794machine # [ 5.015357] systemd[1]: Starting Coldplug All udev Devices...795machine # [ 5.019174] systemd[1]: Listening on Journal Log Access Socket.796machine # [ 5.020173] systemd[1]: Mounted Huge Pages File System.797machine # [ 5.023271] systemd[1]: Mounted POSIX Message Queue File System.798machine # [ 5.025178] systemd[1]: Mounted Kernel Debug File System.799machine # [ 5.026142] systemd[1]: Mounted Kernel Trace File System.800machine # [ 5.030033] systemd[1]: Finished Create List of Static Device Nodes.801machine # [ 5.031490] systemd[1]: modprobe@configfs.service: Deactivated successfully.802machine # [ 5.033790] systemd[1]: Finished Load Kernel Module configfs.803machine # [ 5.035583] systemd[1]: Mounted FUSE Control File System.804machine # [ 5.039180] systemd[1]: Mounting Kernel Configuration File System...805machine # [ 5.044411] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...806machine # [ 5.045612] EXT4-fs (vda): re-mounted 9bb956bf-81dc-4ac2-b27d-c9d678fa930a.807machine # [ 5.051674] systemd[1]: Finished Remount Root and Kernel File Systems.808machine # [ 5.054970] systemd[1]: Listening on Disk Image Download Service Socket.809machine # [ 5.058422] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore810machine # [ 5.064652] systemd[1]: Starting Load/Save OS Random Seed...811machine # [ 5.065528] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os812machine # [ 5.070396] systemd[1]: Mounted Kernel Configuration File System.813machine # [ 5.078096] systemd-journald[308]: Collecting audit messages is enabled.814machine # [ 5.090060] loop: module loaded815machine # [ 5.094551] systemd[1]: Finished Load Kernel Modules.816machine # [ 5.100782] systemd[1]: Starting Apply Kernel Variables...817machine # [ 4.954802] systemd[1]: Queued start job for default target Multi-User System.818machine # [ 5.105106] systemd[1]: Started Journal Service.819machine # [ 4.961289] systemd[1]: systemd-journald.service: Deactivated successfully.820machine # [ 4.964380] systemd-modules-load[309]: Using 2 probe threads821machine # [ 4.966290] systemd-modules-load[309]: Inserted module 'loop'822machine # [ 4.968444] systemd[1]: Starting Flush Journal to Persistent Storage...823machine # [ 4.973356] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.824machine # [ 4.974929] systemd[1]: Finished Load/Save OS Random Seed.825machine # [ 4.985770] systemd-oomd[310]: No swap; memory pressure usage will be degraded826machine # [ 4.991493] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.827machine # [ 5.143824] systemd-journald[308]: Received client request to flush runtime journal.828machine # [ 5.053513] systemd[1]: Reached target First Boot Complete.829machine # [ 5.055025] systemd[1]: Starting Create Static Device Nodes in /dev...830machine # [ 5.057332] systemd[1]: Finished Apply Kernel Variables.831machine # [ 5.058297] systemd[1]: Finished Create Static Device Nodes in /dev.832machine # [ 5.060396] systemd[1]: Reached target Preparation for Local File Systems.833machine # [ 5.062296] systemd[1]: Starting Rule-based Manager for Device Events and Files...834machine # [ 5.064386] systemd[1]: Finished Flush Journal to Persistent Storage.835machine # [ 5.074425] systemd-udevd[333]: Using default interface naming scheme 'v261'.836machine # [ 5.104590] systemd[1]: Started Rule-based Manager for Device Events and Files.837machine # [ 5.119831] systemd[1]: Finished Coldplug All udev Devices.838machine # [ 5.177271] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse839machine # [ 5.220648] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.840machine # [ 5.222490] systemd[1]: Condition check resulted in /dev/ttyS0 being skipped.841machine # [ 5.242823] (udev-worker)[343]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.842machine # [ 5.245313] (udev-worker)[343]: Network interface NamePolicy= disabled on kernel command line.843machine # [ 5.249210] (udev-worker)[352]: Network interface NamePolicy= disabled on kernel command line.844machine # [ 5.278789] systemd[1]: Condition check resulted in Virtio network device being skipped.845machine # [ 5.281081] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore846machine # [ 5.282593] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67847machine # [ 5.284755] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore848machine # [ 5.286280] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os849machine # [ 5.287585] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os850machine # [ 5.471572] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3851machine # [ 5.474107] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:06.0/virtio4/input/input4852machine # [ 5.477041] bochs-drm 0000:00:01.0: vgaarb: deactivate vga console853machine # [ 5.484893] ACPI: button: Power Button [PWRF]854machine # [ 5.490621] Console: switching to colour dummy device 80x25855machine # [ 5.492007] [drm] Found bochs VGA, ID 0xb0c5.856machine # [ 5.492009] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.857machine # [ 5.494770] bochs-drm 0000:00:01.0: [drm] Registered 1 planes with drm panic858machine # [ 5.496004] [drm] Initialized bochs-drm 1.0.0 for 0000:00:01.0 on minor 0859machine # [ 5.510680] Console: switching to colour frame buffer device 160x50860machine # [ 5.511104] mousedev: PS/2 mouse device common for all mice861machine # [ 5.512760] bochs-drm 0000:00:01.0: [drm] fb0: bochs-drmdrmfb frame buffer device862machine # [ 5.542494] rtc_cmos PNP0B00:00: RTC can wake from S4863machine # [ 5.543158] lpc_ich 0000:00:1f.0: I/O space for GPIO uninitialized864machine # [ 5.546006] rtc_cmos PNP0B00:00: registered as rtc0865machine # [ 5.546671] rtc_cmos PNP0B00:00: setting system clock to 2026-09-20T15:39:13 UTC (1789918753)866machine # [ 5.546708] parport_pc 00:02: reported by Plug and Play ACPI867machine # [ 5.548121] rtc_cmos PNP0B00:00: alarms up to one day, y3k, 242 bytes nvram, hpet irqs868machine # [ 5.549541] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]869machine # [ 5.583775] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6870machine # [ 5.585802] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5871machine # [ 5.591520] i801_smbus 0000:00:1f.3: SMBus using PCI interrupt872machine # [ 5.597142] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD873machine # [ 5.475657] systemd[1]: Starting Virtual Console Setup...874machine # [ 5.490065] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.875machine # [ 5.491271] systemd[1]: Stopped Virtual Console Setup.876machine # [ 5.492388] systemd[1]: Starting Virtual Console Setup...877machine # [ 5.534072] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.878machine # [ 5.686516] ppdev: user-space parallel port driver879machine # [ 5.538328] systemd[1]: Stopped Virtual Console Setup.880machine # [ 5.544357] systemd[1]: Starting Virtual Console Setup...881machine # [ 5.737774] iTCO_wdt iTCO_wdt.0.auto: Found a ICH9 TCO device (Version=2, TCOBASE=0x0660)882machine # [ 5.739098] iTCO_wdt iTCO_wdt.0.auto: initialized. heartbeat=30 sec (nowayout=0)883machine # [ 5.763957] kvm_amd: TSC scaling supported884machine # [ 5.764464] kvm_amd: Nested Virtualization enabled885machine # [ 5.764951] kvm_amd: Nested Paging enabled886machine # [ 5.765411] kvm_amd: LBR virtualization supported887machine # [ 5.765904] kvm_amd: Virtual VMLOAD VMSAVE supported888machine # [ 5.766451] kvm_amd: Virtual GIF supported889machine # [ 5.766876] kvm_amd: Virtual NMI enabled890machine # [ 5.820548] EDAC MC: Ver: 3.0.0891machine # [ 5.731724] systemd-vconsole-setup[377]: Configuration of first virtual console was skipped, ignoring remaining ones.892machine # [ 5.734402] systemd[1]: Finished Virtual Console Setup.893machine # [ 5.760160] systemd[1]: Mounting /run/wrappers...894machine # [ 5.779771] systemd[1]: Mounted /run/wrappers.895machine # [ 5.780604] systemd[1]: Reached target Local File Systems.896machine # [ 5.781501] systemd[1]: Listening on Boot Loader Control Service Socket.897machine # [ 5.782506] systemd[1]: Starting register-nix-paths.service...898machine # [ 5.783772] systemd[1]: Starting Create SUID/SGID Wrappers...899machine # [ 5.784920] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.900machine # [ 5.787204] systemd[1]: Starting Save Transient machine-id to Disk...901machine # [ 5.788728] systemd[1]: Starting Create System Files and Directories...902machine # [ 5.837779] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.903machine # [ 5.865381] systemd[1]: Finished Save Transient machine-id to Disk.904machine # [ 5.868400] systemd[1]: Finished Create System Files and Directories.905machine # [ 5.872406] systemd[1]: Starting Rebuild Journal Catalog...906machine # [ 5.875531] systemd[1]: Starting Record System Boot/Shutdown in UTMP...907machine # [ 5.905343] systemd[1]: Finished Record System Boot/Shutdown in UTMP.908machine # [ 5.923888] systemd[1]: Finished Rebuild Journal Catalog.909machine # [ 5.926334] systemd[1]: Starting Update is Completed...910machine # [ 5.954101] systemd[1]: Finished Update is Completed.911machine # [ 6.072121] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.912machine # [ 6.074107] systemd[1]: Finished Create SUID/SGID Wrappers.913machine # [ 6.101480] systemd[1]: Finished register-nix-paths.service.914machine # [ 6.102448] systemd[1]: Reached target System Initialization.915machine # [ 6.103547] systemd[1]: Started Discard unused filesystem blocks once a week.916machine # [ 6.104517] systemd[1]: Started Daily Cleanup of Temporary Directories.917machine # [ 6.105409] systemd[1]: Reached target Timer Units.918machine # [ 6.106220] systemd[1]: Listening on D-Bus System Message Bus Socket.919machine # [ 6.107079] systemd[1]: Listening on Nix Daemon Socket.920machine # [ 6.107848] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.921machine # [ 6.108957] systemd[1]: Reached target Socket Units.922machine # [ 6.109663] systemd[1]: Reached target Basic System.923machine # [ 6.111729] systemd[1]: Started backdoor.service.924machine # [ 6.113023] systemd[1]: Starting Import lastlog data into lastlog2 database...925machine # [ 6.115786] systemd[1]: Starting Name Service Cache Daemon (nsncd)...926machine # [ 6.120248] systemd[1]: Starting Post-Boot Actions...927machine # [ 6.121953] systemd[1]: Started Reset console on configuration changes.928machine # [ 6.125245] systemd[1]: Starting resolvconf update...929machine # [ 6.128880] systemd[1]: Started rustfs.service.930machine # [ 6.134384] systemd[1]: Starting rustfs-setup.service...931machine # [ 6.141259] systemd[1]: Starting D-Bus System Message Bus...932machine # [ 6.183844] systemd[1]: Finished Post-Boot Actions.933machine # connecting to host...934machine # [ 6.202509] systemd[1]: Started Name Service Cache Daemon (nsncd).935machine # [ 6.203398] systemd[1]: Reached target Host and Network Name Lookups.936machine # [ 6.204384] systemd[1]: Reached target User and Group Name Lookups.937machine # [ 6.207717] nsncd[458]: Sep 20 15:39:14.310 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"938machine # [ 6.212650] systemd[1]: Starting User Login Management...939machine # [ 6.221846] systemd[1]: Finished Import lastlog data into lastlog2 database.940machine: Guest shell says: b'Spawning backdoor root shell...\n'941machine: connected to guest root shell942machine: (connecting took 6.91 seconds)943machine: (finished: waiting for the VM to finish booting, in 7.14 seconds)944machine # [ 6.284326] dbus-broker-launch[465]: Looking up NSS user entry for 'systemd-timesync'...945machine # [ 6.295173] dbus-broker-launch[465]: NSS returned no entry for 'systemd-timesync'946machine # [ 6.296126] dbus-broker-launch[465]: Invalid user-name in /nix/store/r5vfiplyifxring919f1fiblhv2l5pjx-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"947machine # [ 6.316249] systemd-logind[489]: New seat seat0.948machine # [ 6.320347] systemd-logind[489]: Watching system buttons on /dev/input/event2 (Power Button)949machine # [ 6.320678] systemd-logind[489]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)950machine # [ 6.321089] systemd-logind[489]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)951machine # [ 6.321404] systemd[1]: Started User Login Management.952machine # [ 6.327374] systemd[1]: Starting linger-users.service...953machine # [ 6.335322] systemd[1]: Started D-Bus System Message Bus.954machine # [ 6.335610] systemd[1]: Stopped target Host and Network Name Lookups.955machine # [ 6.336084] systemd[1]: Stopping Host and Network Name Lookups...956machine # [ 6.336530] systemd[1]: Stopped target User and Group Name Lookups.957machine # [ 6.339364] systemd[1]: Stopping User and Group Name Lookups...958machine # [ 6.340259] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...959machine # [ 6.347150] systemd[1]: nscd.service: Deactivated successfully.960machine # [ 6.351774] systemd[1]: Stopped Name Service Cache Daemon (nsncd).961machine # [ 6.354985] systemd[1]: Starting Name Service Cache Daemon (nsncd)...962machine # [ 6.372583] dbus-broker-launch[465]: Ready963machine # [ 6.386068] systemd[1]: linger-users.service: Deactivated successfully.964machine # [ 6.387469] systemd[1]: Finished linger-users.service.965machine # [ 6.403792] systemd[1]: Started Name Service Cache Daemon (nsncd).966machine # [ 6.404700] nsncd[557]: Sep 20 15:39:14.507 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"967machine # [ 6.408045] systemd[1]: Reached target Host and Network Name Lookups.968machine # [ 6.409217] systemd[1]: Reached target User and Group Name Lookups.969machine # [ 6.432178] systemd[1]: Finished resolvconf update.970machine # [ 6.433380] systemd[1]: Reached target Preparation for Network.971machine # [ 6.436784] systemd[1]: Starting DHCP Client...972machine # [ 6.439683] systemd[1]: Starting Address configuration of eth1...973machine # [ 6.444263] systemd[1]: Starting Extra networking commands....974machine # [ 6.533206] network-addresses-eth1-start[590]: adding address 192.168.1.1/24... done975machine # [ 6.548222] network-addresses-eth1-start[590]: adding address 2001:db8:1::1/64... done976machine # [ 6.559774] dhcpcd[600]: dhcpcd-10.3.2 starting977machine # [ 6.563817] systemd[1]: Finished Address configuration of eth1.978machine # [ 6.566356] dhcpcd[634]: dev: loaded udev979machine # [ 6.732026] 8021q: 802.1Q VLAN Support v1.8980machine # [ 6.733092] 8021q: adding VLAN 0 to HW filter on device eth1981machine # [ 6.601685] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.982machine # [ 6.609423] systemd[1]: Finished Extra networking commands..983machine # [ 6.611923] systemd[1]: Reached target Network.984machine # [ 6.618098] systemd[1]: Starting PostgreSQL Server...985machine # [ 6.621599] systemd[1]: Starting Permit User Sessions...986machine # [ 6.820912] cfg80211: Loading compiled-in X.509 certificates for regulatory database987machine # [ 6.679333] systemd[1]: Finished Permit User Sessions.988machine # [ 6.682462] systemd[1]: Started Getty on tty1.989machine # [ 6.682788] systemd[1]: Reached target Login Prompts.990machine # [ 6.846516] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'991machine # [ 6.847770] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'992machine # [ 6.850533] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2993machine # [ 6.851774] cfg80211: failed to load regulatory.db994machine # [ 6.894357] 8021q: adding VLAN 0 to HW filter on device eth0995machine # [ 6.745778] dhcpcd[634]: eth0: waiting for carrier996machine # [ 6.747379] dhcpcd[634]: eth0: carrier acquired997machine # [ 6.754591] dhcpcd[634]: DUID 00:01:00:01:32:42:ba:a2:52:54:00:12:34:56998machine # [ 6.755658] dhcpcd[634]: eth0: IAID 00:12:34:56999machine # [ 6.756421] dhcpcd[634]: eth0: adding address fe80::5054:ff:fe12:34561000machine # [ 6.784763] postgresql-pre-start[677]: The files belonging to this database system will be owned by user "postgres".1001machine # [ 6.785167] postgresql-pre-start[677]: This user must also own the server process.1002machine # [ 6.791899] postgresql-pre-start[677]: The database cluster will be initialized with locale "en_US.UTF-8".1003machine # [ 6.792488] postgresql-pre-start[677]: The default database encoding has accordingly been set to "UTF8".1004machine # [ 6.792967] postgresql-pre-start[677]: The default text search configuration will be set to "english".1005machine # [ 6.793778] postgresql-pre-start[677]: Data page checksums are enabled.1006machine # [ 6.796144] postgresql-pre-start[677]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok1007machine # [ 6.798095] postgresql-pre-start[677]: creating subdirectories ... ok1008machine # [ 6.799024] postgresql-pre-start[677]: selecting dynamic shared memory implementation ... posix1009machine # [ 6.861326] postgresql-pre-start[677]: selecting default "max_connections" ... 1001010machine # [ 6.905641] postgresql-pre-start[677]: selecting default "shared_buffers" ... 128MB1011machine # [ 7.565989] postgresql-pre-start[677]: selecting default time zone ... UTC1012machine # [ 7.568522] postgresql-pre-start[677]: creating configuration files ... ok1013machine # [ 7.720739] postgresql-pre-start[677]: running bootstrap script ... ok1014machine # [ 7.979517] dhcpcd[634]: eth0: soliciting a DHCP lease1015machine # [ 8.137558] NET: Registered PF_PACKET protocol family1016machine # [ 7.994512] dhcpcd[634]: eth0: offered 10.0.2.15 from 10.0.2.21017machine # [ 7.997155] dhcpcd[634]: eth0: probing address 10.0.2.15/241018machine # [ 8.126603] postgresql-pre-start[677]: performing post-bootstrap initialization ... ok1019machine # [ 8.281149] postgresql-pre-start[677]: syncing data to disk ... ok1020machine # [ 8.281822] postgresql-pre-start[677]: initdb: warning: enabling "trust" authentication for local connections1021machine # [ 8.282514] postgresql-pre-start[677]: 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.1022machine # [ 8.283339] postgresql-pre-start[677]: Success. You can now start the database server using:1023machine # [ 8.283934] postgresql-pre-start[677]: pg_ctl -D /var/lib/postgresql/18 -l logfile start1024machine # [ 8.382846] postgres[708]: [708] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit1025machine # [ 8.384933] postgres[708]: [708] LOG: listening on IPv4 address "0.0.0.0", port 54321026machine # [ 8.386199] postgres[708]: [708] LOG: listening on IPv6 address "::", port 54321027machine # [ 8.387276] postgres[708]: [708] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"1028machine # [ 8.396218] postgres[717]: [717] LOG: database system was shut down at 2026-09-20 15:39:16 GMT1029machine # [ 8.402587] postgres[708]: [708] LOG: database system is ready to accept connections1030machine # [ 8.406846] systemd[1]: Started PostgreSQL Server.1031machine # [ 8.409686] systemd[1]: Starting PostgreSQL Setup Scripts...1032machine # [ 8.555039] postgresql-setup-start[732]: CREATE DATABASE1033machine # [ 8.581555] postgresql-setup-start[742]: CREATE ROLE1034machine # [ 8.596097] postgresql-setup-start[744]: ALTER DATABASE1035machine # [ 8.600783] systemd[1]: Finished PostgreSQL Setup Scripts.1036machine # [ 8.601982] systemd[1]: Reached target PostgreSQL.1037machine # [ 8.760363] dhcpcd[634]: eth0: soliciting an IPv6 router1038machine # [ 8.762667] dhcpcd[634]: eth0: Router Advertisement from fe80::21039machine # [ 8.764783] dhcpcd[634]: eth0: adding address fec0::5054:ff:fe12:3456/641040machine # [ 8.767077] dhcpcd[634]: eth0: adding route to fec0::/641041machine # [ 8.769065] dhcpcd[634]: eth0: adding default route via fe80::21042machine # [ 12.690267] dhcpcd[634]: eth0: leased 10.0.2.15 for 86400 seconds1043machine # [ 12.690659] dhcpcd[634]: eth0: adding route to 10.0.2.0/241044machine # [ 12.692443] dhcpcd[634]: eth0: adding default route via 10.0.2.21045machine # [ 12.808384] systemd[1]: Started DHCP Client.1046machine # [ 12.809037] systemd[1]: Reached target Network is Online.1047machine # [ 12.811165] systemd[1]: Starting k3s service...1048machine # [ 12.857588] k3s[844]: time="2026-09-20T15:39:20Z" level=info msg="Acquiring lock file /var/lib/rancher/k3s/data/.lock"1049machine # [ 12.857772] k3s[844]: time="2026-09-20T15:39:20Z" level=info msg="Preparing data dir /var/lib/rancher/k3s/data/05fb32d1d5d79ab4bf8f805d07e4a7dfb491001fd5137b587aa471efd4746099"1050machine # [ 14.589520] rustfs-setup-start[854]: mb s3://niks31051machine # [ 14.595253] systemd[1]: Finished rustfs-setup.service.1052machine # [ 14.941214] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Starting k3s 1.35.8+k3s1 (e952d68a)"1053machine # [ 14.951440] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdle=20, maxOpen=0, maxLifetime=0s, maxIdleTime=2m0s"1054machine # [ 14.951764] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Kine built with sqlite from github.com/mattn/go-sqlite3 version 3.53.3"1055machine # [ 14.952184] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Configuring database table schema and indexes, this may take a moment..."1056machine # [ 14.963687] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Database tables and indexes are up to date"1057machine # [ 14.964051] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Running startup VACUUM to reclaim disk space, this may take a moment..."1058machine # [ 14.968356] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Startup VACUUM completed successfully"1059machine # [ 14.971548] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Kine available at unix://kine.sock"1060machine # [ 14.971807] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"1061machine # [ 14.974072] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Datastore connection validated successfully, proceeding with bootstrap data generation"1062machine # [ 14.976182] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="generated self-signed CA certificate CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:23.079523374 +0000 UTC notAfter=2036-09-17 14:39:23.079523374 +0000 UTC"1063machine # [ 14.978758] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1064machine # [ 14.981196] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1065machine # [ 14.983700] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1066machine # [ 14.986058] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1067machine # [ 14.988338] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1068machine # [ 14.990686] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1069machine # [ 14.993137] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="generated self-signed CA certificate CN=k3s-server-ca@1789918763: notBefore=2026-09-20 14:39:23.082456987 +0000 UTC notAfter=2036-09-17 14:39:23.082456987 +0000 UTC"1070machine # [ 14.995508] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-server-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1071machine # [ 14.997707] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=kube-scheduler signed by CN=k3s-server-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1072machine # [ 14.999946] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=kube-controller-manager signed by CN=k3s-server-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1073machine # [ 15.002225] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="generated self-signed CA certificate CN=k3s-request-header-ca@1789918763: notBefore=2026-09-20 14:39:23.08403065 +0000 UTC notAfter=2036-09-17 14:39:23.08403065 +0000 UTC"1074machine # [ 15.004650] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1075machine # [ 15.006911] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="generated self-signed CA certificate CN=etcd-server-ca@1789918763: notBefore=2026-09-20 14:39:23.084745546 +0000 UTC notAfter=2036-09-17 14:39:23.084745546 +0000 UTC"1076machine # [ 15.009297] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1077machine # [ 15.011422] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="generated self-signed CA certificate CN=etcd-peer-ca@1789918763: notBefore=2026-09-20 14:39:23.085380263 +0000 UTC notAfter=2036-09-17 14:39:23.085380263 +0000 UTC"1078machine # [ 15.013782] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1079machine # [ 15.015914] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1080machine # [ 15.045065] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1081machine # [ 15.048569] k3s[844]: time="2026-09-20T15:39:23Z" level=warning msg="dynamiclistener [::]:6443: no cached certificate available for preload - deferring certificate load until storage initialization or first client request"1082machine # [ 15.055253] k3s[844]: time="2026-09-20T15:39:23Z" 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__d975_31c3_299f_e85-718ced:fec0::d975:31c3:299f:e85 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=5A3FECDEDCB0FE1852A607BBF51B1E1E8B718872]"1083machine # [ 15.857123] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="Password verified locally for node machine"1084machine # [ 15.858649] k3s[844]: time="2026-09-20T15:39:23Z" level=info msg="certificate CN=machine signed by CN=k3s-server-ca@1789918763: notBefore=2026-09-20 14:39:23 +0000 UTC notAfter=2027-09-20 14:39:23 +0000 UTC"1085machine # [ 16.084144] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="certificate CN=system:node:machine,O=system:nodes signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:24 +0000 UTC notAfter=2027-09-20 14:39:24 +0000 UTC"1086machine # [ 16.182289] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:24 +0000 UTC notAfter=2027-09-20 14:39:24 +0000 UTC"1087machine # [ 16.277948] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1789918763: notBefore=2026-09-20 14:39:24 +0000 UTC notAfter=2027-09-20 14:39:24 +0000 UTC"1088machine # [ 16.376066] k3s[844]: time="2026-09-20T15:39:24Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:34484: runtime core not ready"1089machine # [ 16.449408] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Module overlay was already loaded"1090machine # [ 16.660328] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.1091machine # [ 16.664114] Bridge firewalling registered1092machine # [ 16.520565] k3s[844]: time="2026-09-20T15:39:24Z" level=warning msg="Failed to load kernel module iptable_nat with modprobe"1093machine # [ 16.523884] k3s[844]: time="2026-09-20T15:39:24Z" level=warning msg="Failed to load kernel module iptable_filter with modprobe"1094machine # [ 16.529406] k3s[844]: time="2026-09-20T15:39:24Z" level=warning msg="Failed to load kernel module nft-expr-counter with modprobe"1095machine # [ 16.568821] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400"1096machine # [ 16.569174] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600"1097machine # [ 16.571909] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Set sysctl 'net/ipv4/conf/all/forwarding' to 1"1098machine # [ 16.573237] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 131072"1099machine # [ 16.577759] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Creating k3s-cert-monitor event broadcaster"1100machine # [ 16.578771] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Polling for API server readiness: GET /readyz failed: the server is currently unable to handle the request"1101machine # [ 16.581128] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Saving cluster bootstrap data to datastore"1102machine # [ 16.584321] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Opening etcd client connection with endpoints [unix://kine.sock]"1103machine # [ 16.586211] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Connection to etcd is ready"1104machine # [ 16.586311] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="ETCD server is now running"1105machine # [ 16.588849] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log"1106machine # [ 16.589128] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"1107machine # [ 16.589574] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml"1108machine # [ 16.597064] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Handling backend connection request [machine]"1109machine # [ 16.600146] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"1110machine # [ 16.600769] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"1111machine # [ 16.602068] k3s[844]: time="2026-09-20T15:39:24Z" 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"1112machine # [ 16.604031] k3s[844]: time="2026-09-20T15:39:24Z" 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"1113machine # [ 16.605136] k3s[844]: time="2026-09-20T15:39:24Z" 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"1114machine # [ 16.608213] k3s[844]: time="2026-09-20T15:39:24Z" 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"1115machine # [ 16.613894] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Server node token is available at /var/lib/rancher/k3s/server/token"1116machine # [ 16.616444] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="To join server node to cluster: k3s server -s https://10.0.2.15:6443 -t ${SERVER_NODE_TOKEN}"1117machine # [ 16.617020] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Agent node token is available at /var/lib/rancher/k3s/server/agent-token"1118machine # [ 16.653634] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="To join agent node to cluster: k3s agent -s https://10.0.2.15:6443 -t ${AGENT_NODE_TOKEN}"1119machine # [ 16.654215] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"1120machine # [ 16.654673] k3s[844]: time="2026-09-20T15:39:24Z" level=info msg="Run: k3s kubectl"1121machine # [ 16.655353] k3s[844]: I0920 15:39:24.716611 844 options.go:263] external host was not specified, using 10.0.2.151122machine # [ 16.655790] k3s[844]: I0920 15:39:24.721439 844 server.go:158] Version: v1.35.8+k3s11123machine # [ 16.656386] k3s[844]: I0920 15:39:24.721468 844 server.go:160] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1124machine # [ 16.811171] k3s[844]: I0920 15:39:24.914585 844 plugins.go:157] Loaded 14 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,PodTopologyLabels,MutatingAdmissionPolicy,MutatingAdmissionWebhook.1125machine # [ 16.811350] k3s[844]: I0920 15:39:24.914706 844 plugins.go:160] Loaded 14 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,ClusterTrustBundleAttest,CertificateSubjectRestriction,NodeDeclaredFeatureValidator,ValidatingAdmissionPolicy,ValidatingAdmissionWebhook,ResourceQuota.1126machine # [ 16.813061] k3s[844]: I0920 15:39:24.915778 844 instance.go:240] Using reconciler: lease1127machine # [ 16.813679] k3s[844]: I0920 15:39:24.916175 844 shared_informer.go:349] "Waiting for caches to sync" controller="node_authorizer"1128machine # [ 16.814142] k3s[844]: I0920 15:39:24.916278 844 shared_informer.go:370] "Waiting for caches to sync"1129machine # [ 16.820796] k3s[844]: I0920 15:39:24.924406 844 handler.go:304] Adding GroupVersion apiextensions.k8s.io v1 to ResourceManager1130machine # [ 16.820958] k3s[844]: W0920 15:39:24.924586 844 genericapiserver.go:787] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.1131machine # [ 16.824327] k3s[844]: I0920 15:39:24.927945 844 cidrallocator.go:198] starting ServiceCIDR Allocator Controller1132machine # [ 16.831487] k3s[844]: time="2026-09-20T15:39:24Z" level=error msg="Sending HTTP/1.1 503 response to 127.0.0.1:34528: runtime core not ready"1133machine # [ 16.936737] k3s[844]: I0920 15:39:25.040293 844 handler.go:304] Adding GroupVersion v1 to ResourceManager1134machine # [ 16.938233] k3s[844]: I0920 15:39:25.041830 844 apis.go:112] API group "internal.apiserver.k8s.io" is not enabled, skipping.1135machine # [ 16.965324] k3s[844]: time="2026-09-20T15:39:25Z" 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"1136machine # [ 17.011465] k3s[844]: I0920 15:39:25.115049 844 apis.go:112] API group "storagemigration.k8s.io" is not enabled, skipping.1137machine # [ 17.052153] k3s[844]: I0920 15:39:25.154804 844 handler.go:304] Adding GroupVersion authentication.k8s.io v1 to ResourceManager1138machine # [ 17.052520] k3s[844]: W0920 15:39:25.154834 844 genericapiserver.go:787] Skipping API authentication.k8s.io/v1beta1 because it has no resources.1139machine # [ 17.052942] k3s[844]: W0920 15:39:25.154845 844 genericapiserver.go:787] Skipping API authentication.k8s.io/v1alpha1 because it has no resources.1140machine # [ 17.053569] k3s[844]: I0920 15:39:25.155091 844 handler.go:304] Adding GroupVersion authorization.k8s.io v1 to ResourceManager1141machine # [ 17.053989] k3s[844]: W0920 15:39:25.155104 844 genericapiserver.go:787] Skipping API authorization.k8s.io/v1beta1 because it has no resources.1142machine # [ 17.055462] k3s[844]: I0920 15:39:25.155512 844 handler.go:304] Adding GroupVersion autoscaling v2 to ResourceManager1143machine # [ 17.055894] k3s[844]: I0920 15:39:25.158063 844 handler.go:304] Adding GroupVersion autoscaling v1 to ResourceManager1144machine # [ 17.056566] k3s[844]: W0920 15:39:25.158082 844 genericapiserver.go:787] Skipping API autoscaling/v2beta1 because it has no resources.1145machine # [ 17.059082] k3s[844]: W0920 15:39:25.158093 844 genericapiserver.go:787] Skipping API autoscaling/v2beta2 because it has no resources.1146machine # [ 17.059747] k3s[844]: I0920 15:39:25.160724 844 handler.go:304] Adding GroupVersion batch v1 to ResourceManager1147machine # [ 17.060205] k3s[844]: W0920 15:39:25.160740 844 genericapiserver.go:787] Skipping API batch/v1beta1 because it has no resources.1148machine # [ 17.060668] k3s[844]: I0920 15:39:25.161118 844 handler.go:304] Adding GroupVersion certificates.k8s.io v1 to ResourceManager1149machine # [ 17.061169] k3s[844]: W0920 15:39:25.161133 844 genericapiserver.go:787] Skipping API certificates.k8s.io/v1beta1 because it has no resources.1150machine # [ 17.061318] k3s[844]: W0920 15:39:25.161143 844 genericapiserver.go:787] Skipping API certificates.k8s.io/v1alpha1 because it has no resources.1151machine # [ 17.061770] k3s[844]: I0920 15:39:25.161385 844 handler.go:304] Adding GroupVersion coordination.k8s.io v1 to ResourceManager1152machine # [ 17.064085] k3s[844]: W0920 15:39:25.161398 844 genericapiserver.go:787] Skipping API coordination.k8s.io/v1beta1 because it has no resources.1153machine # [ 17.064624] k3s[844]: W0920 15:39:25.161409 844 genericapiserver.go:787] Skipping API coordination.k8s.io/v1alpha2 because it has no resources.1154machine # [ 17.065084] k3s[844]: I0920 15:39:25.161697 844 handler.go:304] Adding GroupVersion discovery.k8s.io v1 to ResourceManager1155machine # [ 17.065558] k3s[844]: W0920 15:39:25.161712 844 genericapiserver.go:787] Skipping API discovery.k8s.io/v1beta1 because it has no resources.1156machine # [ 17.066903] k3s[844]: I0920 15:39:25.166128 844 handler.go:304] Adding GroupVersion networking.k8s.io v1 to ResourceManager1157machine # [ 17.067691] k3s[844]: W0920 15:39:25.166146 844 genericapiserver.go:787] Skipping API networking.k8s.io/v1beta1 because it has no resources.1158machine # [ 17.069070] k3s[844]: I0920 15:39:25.166371 844 handler.go:304] Adding GroupVersion node.k8s.io v1 to ResourceManager1159machine # [ 17.069293] k3s[844]: W0920 15:39:25.166384 844 genericapiserver.go:787] Skipping API node.k8s.io/v1beta1 because it has no resources.1160machine # [ 17.069753] k3s[844]: W0920 15:39:25.166394 844 genericapiserver.go:787] Skipping API node.k8s.io/v1alpha1 because it has no resources.1161machine # [ 17.070391] k3s[844]: I0920 15:39:25.166776 844 handler.go:304] Adding GroupVersion policy v1 to ResourceManager1162machine # [ 17.070828] k3s[844]: W0920 15:39:25.166791 844 genericapiserver.go:787] Skipping API policy/v1beta1 because it has no resources.1163machine # [ 17.073080] k3s[844]: I0920 15:39:25.167524 844 handler.go:304] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager1164machine # [ 17.073698] k3s[844]: W0920 15:39:25.167540 844 genericapiserver.go:787] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.1165machine # [ 17.074823] k3s[844]: W0920 15:39:25.167550 844 genericapiserver.go:787] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.1166machine # [ 17.075375] k3s[844]: I0920 15:39:25.169805 844 handler.go:304] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager1167machine # [ 17.075798] k3s[844]: W0920 15:39:25.169823 844 genericapiserver.go:787] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.1168machine # [ 17.078071] k3s[844]: W0920 15:39:25.169834 844 genericapiserver.go:787] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.1169machine # [ 17.078378] k3s[844]: I0920 15:39:25.176147 844 handler.go:304] Adding GroupVersion storage.k8s.io v1 to ResourceManager1170machine # [ 17.078840] k3s[844]: W0920 15:39:25.176170 844 genericapiserver.go:787] Skipping API storage.k8s.io/v1beta1 because it has no resources.1171machine # [ 17.079454] k3s[844]: W0920 15:39:25.176181 844 genericapiserver.go:787] Skipping API storage.k8s.io/v1alpha1 because it has no resources.1172machine # [ 17.083064] k3s[844]: I0920 15:39:25.186200 844 handler.go:304] Adding GroupVersion flowcontrol.apiserver.k8s.io v1 to ResourceManager1173machine # [ 17.083925] k3s[844]: W0920 15:39:25.186226 844 genericapiserver.go:787] Skipping API flowcontrol.apiserver.k8s.io/v1beta3 because it has no resources.1174machine # [ 17.085392] k3s[844]: W0920 15:39:25.186238 844 genericapiserver.go:787] Skipping API flowcontrol.apiserver.k8s.io/v1beta2 because it has no resources.1175machine # [ 17.085894] k3s[844]: W0920 15:39:25.186247 844 genericapiserver.go:787] Skipping API flowcontrol.apiserver.k8s.io/v1beta1 because it has no resources.1176machine # [ 17.092227] k3s[844]: I0920 15:39:25.195840 844 handler.go:304] Adding GroupVersion apps v1 to ResourceManager1177machine # [ 17.095059] k3s[844]: W0920 15:39:25.197695 844 genericapiserver.go:787] Skipping API apps/v1beta2 because it has no resources.1178machine # [ 17.095683] k3s[844]: W0920 15:39:25.197714 844 genericapiserver.go:787] Skipping API apps/v1beta1 because it has no resources.1179machine # [ 17.099317] k3s[844]: I0920 15:39:25.202894 844 handler.go:304] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager1180machine # [ 17.101082] k3s[844]: W0920 15:39:25.204703 844 genericapiserver.go:787] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.1181machine # [ 17.103057] k3s[844]: W0920 15:39:25.205377 844 genericapiserver.go:787] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources.1182machine # [ 17.103712] k3s[844]: I0920 15:39:25.206037 844 handler.go:304] Adding GroupVersion events.k8s.io v1 to ResourceManager1183machine # [ 17.104157] k3s[844]: W0920 15:39:25.206053 844 genericapiserver.go:787] Skipping API events.k8s.io/v1beta1 because it has no resources.1184machine # [ 17.108513] k3s[844]: I0920 15:39:25.212125 844 handler.go:304] Adding GroupVersion resource.k8s.io v1 to ResourceManager1185machine # [ 17.111050] k3s[844]: W0920 15:39:25.212757 844 genericapiserver.go:787] Skipping API resource.k8s.io/v1beta2 because it has no resources.1186machine # [ 17.111741] k3s[844]: W0920 15:39:25.212778 844 genericapiserver.go:787] Skipping API resource.k8s.io/v1beta1 because it has no resources.1187machine # [ 17.112185] k3s[844]: W0920 15:39:25.212788 844 genericapiserver.go:787] Skipping API resource.k8s.io/v1alpha3 because it has no resources.1188machine # [ 17.125715] k3s[844]: I0920 15:39:25.229320 844 handler.go:304] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager1189machine # [ 17.125912] k3s[844]: W0920 15:39:25.229540 844 genericapiserver.go:787] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.1190machine # [ 17.504155] k3s[844]: I0920 15:39:25.606721 844 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1191machine # [ 17.504358] k3s[844]: I0920 15:39:25.606884 844 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1192machine # [ 17.504778] k3s[844]: I0920 15:39:25.606976 844 secure_serving.go:211] Serving securely on 127.0.0.1:64441193machine # [ 17.505462] k3s[844]: I0920 15:39:25.607055 844 remote_available_controller.go:425] Starting RemoteAvailability controller1194machine # [ 17.507089] k3s[844]: I0920 15:39:25.607071 844 cache.go:32] Waiting for caches to sync for RemoteAvailability controller1195machine # [ 17.507736] k3s[844]: I0920 15:39:25.607106 844 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"1196machine # [ 17.508202] k3s[844]: I0920 15:39:25.607172 844 tlsconfig.go:243] "Starting DynamicServingCertificateController"1197machine # [ 17.508693] k3s[844]: I0920 15:39:25.607816 844 apf_controller.go:377] Starting API Priority and Fairness config controller1198machine # [ 17.511088] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Starting legacy_token_tracking_controller" logger=k3s1199machine # [ 17.511670] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Waiting for caches to sync" logger=k3s1200machine # [ 17.512128] k3s[844]: I0920 15:39:25.609966 844 aggregator.go:185] waiting for initial CRD sync...1201machine # [ 17.512599] k3s[844]: I0920 15:39:25.610539 844 apiservice_controller.go:100] Starting APIServiceRegistrationController1202machine # [ 17.513197] k3s[844]: I0920 15:39:25.610553 844 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller1203machine # [ 17.513649] k3s[844]: I0920 15:39:25.610588 844 controller.go:78] Starting OpenAPI AggregationController1204machine # [ 17.514104] k3s[844]: I0920 15:39:25.610625 844 controller.go:80] Starting OpenAPI V3 AggregationController1205machine # [ 17.514584] k3s[844]: I0920 15:39:25.612849 844 system_namespaces_controller.go:66] Starting system namespaces controller1206machine # [ 17.516126] k3s[844]: I0920 15:39:25.613026 844 cluster_authentication_trust_controller.go:459] Starting cluster_authentication_trust_controller controller1207machine # [ 17.516787] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Waiting for caches to sync" logger=k3s1208machine # [ 17.518073] k3s[844]: I0920 15:39:25.613116 844 controller.go:113] "Deleting old lease on startup" lease="kube-system/apiserver-ik4pcwfs7qgdl76byc4pomgvia"1209machine # [ 17.518599] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Starting apiserver lease garbage collector" logger=k3s1210machine # [ 17.519086] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Waiting for caches to sync" logger=k3s1211machine # [ 17.519549] k3s[844]: I0920 15:39:25.613560 844 customresource_discovery_controller.go:294] Starting DiscoveryController1212machine # [ 17.524069] k3s[844]: I0920 15:39:25.627039 844 default_servicecidr_controller.go:110] Starting kubernetes-service-cidr-controller1213machine # [ 17.524631] k3s[844]: I0920 15:39:25.627066 844 shared_informer.go:349] "Waiting for caches to sync" controller="kubernetes-service-cidr-controller"1214machine # [ 17.525107] k3s[844]: I0920 15:39:25.627120 844 crdregistration_controller.go:114] Starting crd-autoregister controller1215machine # [ 17.525550] k3s[844]: I0920 15:39:25.627130 844 shared_informer.go:349] "Waiting for caches to sync" controller="crd-autoregister"1216machine # [ 17.526415] k3s[844]: I0920 15:39:25.630034 844 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt"1217machine # [ 17.527488] k3s[844]: I0920 15:39:25.630821 844 dynamic_cafile_content.go:161] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt"1218machine # [ 17.529054] k3s[844]: I0920 15:39:25.632111 844 controller.go:142] Starting OpenAPI controller1219machine # [ 17.529690] k3s[844]: I0920 15:39:25.632177 844 controller.go:90] Starting OpenAPI V3 controller1220machine # [ 17.532076] k3s[844]: I0920 15:39:25.632205 844 naming_controller.go:305] Starting NamingConditionController1221machine # [ 17.532632] k3s[844]: I0920 15:39:25.632260 844 nonstructuralschema_controller.go:202] Starting NonStructuralSchemaConditionController1222machine # [ 17.533087] k3s[844]: I0920 15:39:25.632287 844 apiapproval_controller.go:196] Starting KubernetesAPIApprovalPolicyConformantConditionController1223machine # [ 17.533548] k3s[844]: I0920 15:39:25.632317 844 crd_finalizer.go:273] Starting CRDFinalizer1224machine # [ 17.534046] k3s[844]: I0920 15:39:25.632388 844 repairip.go:210] Starting ipallocator-repair-controller1225machine # [ 17.534490] k3s[844]: I0920 15:39:25.632400 844 shared_informer.go:349] "Waiting for caches to sync" controller="ipallocator-repair-controller"1226machine # [ 17.551252] k3s[844]: I0920 15:39:25.654806 844 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"1227machine # [ 17.554060] k3s[844]: I0920 15:39:25.657399 844 local_available_controller.go:156] Starting LocalAvailability controller1228machine # [ 17.554468] k3s[844]: I0920 15:39:25.657426 844 cache.go:32] Waiting for caches to sync for LocalAvailability controller1229machine # [ 17.607067] k3s[844]: I0920 15:39:25.710635 844 cache.go:39] Caches are synced for APIServiceRegistrationController controller1230machine # [ 17.608152] k3s[844]: I0920 15:39:25.711779 844 handler_discovery.go:451] Starting ResourceDiscoveryManager1231machine # [ 17.613057] k3s[844]: I0920 15:39:25.716440 844 shared_informer.go:377] "Caches are synced"1232machine # [ 17.613377] k3s[844]: I0920 15:39:25.716470 844 policy_source.go:248] refreshing policies1233machine # [ 17.613834] k3s[844]: I0920 15:39:25.716594 844 controller.go:667] quota admission added evaluator for: namespaces1234machine # [ 17.624060] k3s[844]: I0920 15:39:25.727245 844 shared_informer.go:356] "Caches are synced" controller="crd-autoregister"1235machine # [ 17.624389] k3s[844]: I0920 15:39:25.727397 844 shared_informer.go:356] "Caches are synced" controller="kubernetes-service-cidr-controller"1236machine # [ 17.624831] k3s[844]: I0920 15:39:25.727421 844 default_servicecidr_controller.go:169] Creating default ServiceCIDR with CIDRs: [10.43.0.0/16]1237machine # [ 17.626772] k3s[844]: I0920 15:39:25.727585 844 aggregator.go:187] initial CRD sync complete...1238machine # [ 17.627475] k3s[844]: I0920 15:39:25.727599 844 autoregister_controller.go:144] Starting autoregister controller1239machine # [ 17.627977] k3s[844]: I0920 15:39:25.727610 844 cache.go:32] Waiting for caches to sync for autoregister controller1240machine # [ 17.628530] k3s[844]: I0920 15:39:25.727621 844 cache.go:39] Caches are synced for autoregister controller1241machine # [ 17.629392] k3s[844]: I0920 15:39:25.732759 844 shared_informer.go:356] "Caches are synced" controller="ipallocator-repair-controller"1242machine # [ 17.642058] k3s[844]: I0920 15:39:25.745366 844 cidrallocator.go:302] created ClusterIP allocator for Service CIDR 10.43.0.0/161243machine # [ 17.642361] k3s[844]: I0920 15:39:25.745518 844 default_servicecidr_controller.go:231] Setting default ServiceCIDR condition Ready to True1244machine # [ 17.651052] k3s[844]: I0920 15:39:25.754543 844 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161245machine # [ 17.653881] k3s[844]: I0920 15:39:25.757494 844 cache.go:39] Caches are synced for LocalAvailability controller1246machine # [ 17.667058] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="containerd is now running"1247machine # [ 17.668342] k3s[844]: I0920 15:39:25.771961 844 controller.go:667] quota admission added evaluator for: leases.coordination.k8s.io1248machine # [ 17.679906] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-amd64.tar.zst"1249machine # [ 17.704377] k3s[844]: I0920 15:39:25.807973 844 cache.go:39] Caches are synced for RemoteAvailability controller1250machine # [ 17.704959] k3s[844]: I0920 15:39:25.807955 844 apf_controller.go:382] Running API Priority and Fairness config worker1251machine # [ 17.706024] k3s[844]: I0920 15:39:25.808429 844 apf_controller.go:385] Running API Priority and Fairness periodic rebalancing process1252machine # [ 17.707413] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Caches are synced" logger=k3s1253machine # [ 17.710182] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Caches are synced" logger=k3s1254machine # [ 17.711483] k3s[844]: time="2026-09-20T15:39:25Z" level=info msg="Caches are synced" logger=k3s1255machine # [ 17.712668] k3s[844]: I0920 15:39:25.816268 844 shared_informer.go:356] "Caches are synced" controller="node_authorizer"1256machine # [ 17.722241] k3s[844]: I0920 15:39:25.825827 844 alloc.go:329] "allocated clusterIPs" service="default/kubernetes" clusterIPs={"IPv4":"10.43.0.1"}1257machine # [ 17.731476] k3s[844]: W0920 15:39:25.835089 844 lease.go:265] Resetting endpoints for master service "kubernetes" to [10.0.2.15]1258machine # [ 17.733391] k3s[844]: I0920 15:39:25.836995 844 controller.go:667] quota admission added evaluator for: endpoints1259machine # [ 17.739513] k3s[844]: I0920 15:39:25.842910 844 controller.go:667] quota admission added evaluator for: endpointslices.discovery.k8s.io1260machine # [ 17.747594] k3s[844]: E0920 15:39:25.851187 844 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 Service1261machine # [ 18.511368] k3s[844]: I0920 15:39:26.614003 844 storage_scheduling.go:123] created PriorityClass system-node-critical with value 20000010001262machine # [ 18.518880] k3s[844]: I0920 15:39:26.622483 844 storage_scheduling.go:123] created PriorityClass system-cluster-critical with value 20000000001263machine # [ 18.520693] k3s[844]: I0920 15:39:26.624246 844 storage_scheduling.go:139] all system priority classes are created successfully or already exist.1264machine # [ 18.581485] k3s[844]: time="2026-09-20T15:39:26Z" level=info msg="Polling for API server readiness: GET /readyz failed: unknown"1265machine # [ 19.629098] k3s[844]: I0920 15:39:27.732310 844 controller.go:667] quota admission added evaluator for: roles.rbac.authorization.k8s.io1266machine # [ 19.706869] k3s[844]: I0920 15:39:27.810419 844 controller.go:667] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io1267machine # [ 20.589091] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Waiting for untainted node"1268machine # [ 20.594888] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Kube API server is now running"1269machine # [ 20.595201] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="k3s is up and running"1270machine # [ 20.599907] systemd[1]: Started k3s service.1271machine # [ 20.600759] systemd[1]: Reached target Multi-User System.1272machine # [ 20.601665] k3s[844]: time="2026-09-20T15:39:28Z" 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=Normal1273machine # [ 20.604668] systemd[1]: Startup finished in 1.026s (kernel) + 2.725s (initrd) + 16.845s (userspace) = 20.598s.1274machine # [ 20.606206] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Creating k3s-supervisor event broadcaster"1275machine # [ 20.629943] k3s[844]: I0920 15:39:28.733293 844 controllermanager.go:189] "Starting" version="v1.35.8+k3s1"1276machine # [ 20.631415] k3s[844]: I0920 15:39:28.733317 844 controllermanager.go:191] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1277machine # [ 20.636284] k3s[844]: I0920 15:39:28.739898 844 secure_serving.go:211] Serving securely on 127.0.0.1:102571278machine # [ 20.639218] k3s[844]: I0920 15:39:28.740163 844 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1279machine # [ 20.642071] k3s[844]: I0920 15:39:28.741389 844 shared_informer.go:370] "Waiting for caches to sync"1280machine # [ 20.643440] k3s[844]: I0920 15:39:28.740032 844 tlsconfig.go:243] "Starting DynamicServingCertificateController"1281machine # [ 20.646558] k3s[844]: I0920 15:39:28.740060 844 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"1282machine # [ 20.646988] k3s[844]: I0920 15:39:28.740098 844 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1283machine # [ 20.647685] k3s[844]: I0920 15:39:28.741770 844 shared_informer.go:370] "Waiting for caches to sync"1284machine # [ 20.648243] k3s[844]: I0920 15:39:28.740181 844 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1285machine # [ 20.649094] k3s[844]: I0920 15:39:28.741801 844 shared_informer.go:370] "Waiting for caches to sync"1286machine # [ 20.671921] k3s[844]: I0920 15:39:28.775465 844 controller.go:667] quota admission added evaluator for: serviceaccounts1287machine # [ 20.682062] k3s[844]: I0920 15:39:28.784828 844 shared_informer.go:370] "Waiting for caches to sync"1288machine # [ 20.724249] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Creating embedded CRD addons.k3s.cattle.io"1289machine # [ 20.731483] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Creating embedded CRD etcdsnapshotfiles.k3s.cattle.io"1290machine # [ 20.739774] k3s[844]: I0920 15:39:28.843378 844 shared_informer.go:377] "Caches are synced"1291machine # [ 20.740773] k3s[844]: I0920 15:39:28.844302 844 shared_informer.go:377] "Caches are synced"1292machine # [ 20.741936] k3s[844]: I0920 15:39:28.845145 844 shared_informer.go:377] "Caches are synced"1293machine # [ 20.747247] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Creating embedded CRD helmchartconfigs.helm.cattle.io"1294machine # [ 20.752843] k3s[844]: I0920 15:39:28.856416 844 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="podcertificaterequest-cleaner-controller" requiredFeatureGates=["PodCertificateRequest"]1295machine # [ 20.753154] k3s[844]: I0920 15:39:28.856457 844 controllermanager.go:579] "Warning: skipping controller" controller="podcertificaterequest-cleaner-controller"1296machine # [ 20.764759] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Creating embedded CRD helmcharts.helm.cattle.io"1297machine # [ 20.766403] k3s[844]: I0920 15:39:28.870009 844 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1298machine # [ 20.782053] k3s[844]: I0920 15:39:28.885644 844 shared_informer.go:377] "Caches are synced"1299machine # [ 20.788064] k3s[844]: I0920 15:39:28.890876 844 handler.go:304] Adding GroupVersion k3s.cattle.io v1 to ResourceManager1300machine # [ 20.800168] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Waiting for CRD helmchartconfigs.helm.cattle.io to become available"1301machine # [ 20.802490] k3s[844]: I0920 15:39:28.906089 844 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1302machine # [ 20.814380] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Done waiting for CRD helmchartconfigs.helm.cattle.io to become available"1303machine # [ 20.814682] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Waiting for CRD helmcharts.helm.cattle.io to become available"1304machine # [ 20.829065] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Done waiting for CRD helmcharts.helm.cattle.io to become available"1305machine # [ 20.829779] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-40.1.4+up40.1.0.tgz"1306machine # [ 20.831081] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-40.1.4+up40.1.0.tgz"1307machine # [ 20.832103] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml"1308machine # [ 20.834690] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml"1309machine # [ 20.835180] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml"1310machine # [ 20.835793] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml"1311machine # [ 20.836546] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/runtimes.yaml"1312machine # [ 20.837294] k3s[844]: time="2026-09-20T15:39:28Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml"1313machine # [ 20.842163] k3s[844]: I0920 15:39:28.945730 844 handler.go:304] Adding GroupVersion helm.cattle.io v1 to ResourceManager1314machine # [ 20.879404] k3s[844]: I0920 15:39:28.982756 844 node_lifecycle_controller.go:419] "Controller will reconcile labels" logger="node-lifecycle-controller"1315machine # [ 20.879725] k3s[844]: I0920 15:39:28.982807 844 controllermanager.go:627] "Warning: controller is disabled" controller="cloud-node-lifecycle-controller"1316machine # [ 20.973962] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Starting dynamiclistener CN filter node controller with SANs: [127.0.0.1 ::1 localhost machine 10.0.2.15 fec0::d975:31c3:299f:e85 10.43.0.1 kubernetes kubernetes.default kubernetes.default.svc kubernetes.default.svc.cluster.local]"1317machine # [ 20.974163] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tunnel server egress proxy mode: agent"1318machine # [ 21.014701] k3s[844]: W0920 15:39:29.117731 844 probe.go:272] Flexvolume plugin directory at /usr/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating.1319machine # [ 21.045654] k3s[844]: time="2026-09-20T15:39:29Z" 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__d975_31c3_299f_e85-718ced:fec0::d975:31c3:299f:e85 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=5A3FECDEDCB0FE1852A607BBF51B1E1E8B718872]"1320machine # [ 21.076653] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Active TLS secret kube-system/k3s-serving (ver=233) (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__d975_31c3_299f_e85-718ced:fec0::d975:31c3:299f:e85 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=5A3FECDEDCB0FE1852A607BBF51B1E1E8B718872]"1321machine: (finished: waiting for unit k3s.service, in 21.99 seconds)1322machine: waiting for unit rustfs-setup.service1323machine: (finished: waiting for unit rustfs-setup.service, in 0.03 seconds)1324machine: waiting for unit postgresql.service1325machine: (finished: waiting for unit postgresql.service, in 0.04 seconds)1326subtest: chart deploys and becomes ready1327??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1328 File "/nix/store/q8bka5k1zvss9dd482k8ivsflp9lkmxw-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391329machine: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s1330??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.1331 File "/nix/store/q8bka5k1zvss9dd482k8ivsflp9lkmxw-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 391332machine # [ 21.321777] k3s[844]: I0920 15:39:29.425299 844 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="device-taint-eviction-controller" requiredFeatureGates=["DynamicResourceAllocation","DRADeviceTaints"]1333machine # [ 21.321955] k3s[844]: I0920 15:39:29.425330 844 controllermanager.go:579] "Warning: skipping controller" controller="device-taint-eviction-controller"1334machine # [ 21.343190] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/klipper-helm:v0.13.3-build20260727"1335machine # [ 21.347440] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/klipper-helm@sha256:5425a2b4613d2458dbdff99218e8d487ebb59c20e7a941f061c0777070f0aac1"1336machine # [ 21.347933] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/klipper-lb:v0.4.17"1337machine # [ 21.354291] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/klipper-lb@sha256:910944bb0bd94f060a82a56ca1ea1c577d3e49b3473a093a47a985f32e92d94a"1338machine # [ 21.355066] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.37"1339machine # [ 21.359684] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/local-path-provisioner@sha256:e757967a5ec338f6a9b371c5a9688bedaa8c3578ea3dd4db329ea0084be0a86f"1340machine # [ 21.360103] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/mirrored-coredns-coredns:1.14.6"1341machine # [ 21.368080] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/mirrored-coredns-coredns@sha256:900f9c109f7a33545d3c811516e8376df9019147b750f5ce3e254468769176ea"1342machine # [ 21.368895] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/mirrored-library-busybox:1.37.0"1343machine # [ 21.377823] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/mirrored-library-busybox@sha256:101b4afd76732482eff9b95cae5f94bcf295e521fbec4e01b69c5421f3f3f3e5"1344machine # [ 21.378116] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/mirrored-library-traefik:3.7.8"1345machine # [ 21.382760] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/mirrored-library-traefik@sha256:4299bbed850421258fc5448c2e0e6ad350981d4d335a68de11b92448aedbefe5"1346machine # [ 21.383779] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/mirrored-metrics-server:v0.9.0"1347machine # [ 21.396766] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/mirrored-metrics-server@sha256:d9862115e7c7881280d3d75ca26bda8ffc0fc213315979575bf23ce9826205c0"1348machine # [ 21.397610] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported docker.io/rancher/mirrored-pause:3.10.2"1349machine # [ 21.407772] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Tagged docker.io/rancher/mirrored-pause@sha256:f548e0e8e3dc1896ca956272154dde3314e8cc4fde0a57577ee9fa1c63f5baf4"1350machine # Error from server (NotFound): namespaces "niks3" not found1351machine # [ 21.651078] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Imported 8 images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-amd64.tar.zst in 3.970934294s"1352machine # [ 21.653260] k3s[844]: time="2026-09-20T15:39:29Z" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/niks3-server.tar"1353machine # [ 21.687468] k3s[844]: time="2026-09-20T15:39:29Z" 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::d975:31c3:299f:e85 --node-labels= --read-only-port=0"1354machine # [ 21.691611] k3s[844]: 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.1355machine # [ 21.697330] k3s[844]: I0920 15:39:29.800931 844 server.go:521] "Kubelet version" kubeletVersion="v1.35.8+k3s1"1356machine # [ 21.698615] k3s[844]: I0920 15:39:29.800953 844 server.go:523] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1357machine # [ 21.699982] k3s[844]: I0920 15:39:29.800981 844 watchdog_linux.go:95] "Systemd watchdog is not enabled"1358machine # [ 21.701426] k3s[844]: I0920 15:39:29.800993 844 watchdog_linux.go:138] "Systemd watchdog is not enabled or the interval is invalid, so health checking will not be started."1359machine # [ 21.703562] k3s[844]: I0920 15:39:29.802319 844 dynamic_cafile_content.go:161] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt"1360machine # [ 21.706167] k3s[844]: I0920 15:39:29.805791 844 server.go:1414] "Using cgroup driver setting received from the CRI runtime" cgroupDriver="systemd"1361machine # [ 21.708284] k3s[844]: I0920 15:39:29.809885 844 server.go:771] "--cgroups-per-qos enabled, but --cgroup-root was not specified. Defaulting to /"1362machine # [ 21.708545] k3s[844]: I0920 15:39:29.809909 844 server.go:832] "NoSwap is set due to memorySwapBehavior not specified" memorySwapBehavior="" FailSwapOn=false1363machine # [ 21.709260] k3s[844]: I0920 15:39:29.810263 844 container_manager_linux.go:272] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]1364machine # [ 21.709795] k3s[844]: I0920 15:39:29.810289 844 container_manager_linux.go:277] "Creating Container Manager object based on Node Config" nodeConfig={"NodeName":"machine","RuntimeCgroupsName":"","SystemCgroupsName":"","KubeletCgroupsName":"","KubeletOOMScoreAdj":-999,"ContainerRuntime":"","CgroupsPerQOS":true,"CgroupRoot":"/","CgroupDriver":"systemd","KubeletRootDir":"/var/lib/kubelet","ProtectKernelDefaults":false,"KubeReservedCgroupName":"","SystemReservedCgroupName":"","ReservedSystemCPUs":{},"EnforceNodeAllocatable":{"pods":{}},"KubeReserved":null,"SystemReserved":null,"HardEvictionThresholds":[{"Signal":"imagefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"Signal":"nodefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null}],"QOSReserved":{},"CPUManagerPolicy":"none","CPUManagerPolicyOptions":null,"TopologyManagerScope":"container","CPUManagerReconcilePeriod":10000000000,"MemoryManagerPolicy":"None","MemoryManagerReservedMemory":null,"PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null,"CgroupVersion":2}1365machine # [ 21.710541] k3s[844]: I0920 15:39:29.810453 844 topology_manager.go:143] "Creating topology manager with none policy"1366machine # [ 21.711044] k3s[844]: I0920 15:39:29.810482 844 container_manager_linux.go:308] "Creating device plugin manager"1367machine # [ 21.711550] k3s[844]: I0920 15:39:29.810550 844 container_manager_linux.go:317] "Creating Dynamic Resource Allocation (DRA) manager"1368machine # [ 21.734804] k3s[844]: I0920 15:39:29.838244 844 state_mem.go:41] "Initialized" logger="CPUManager state memory"1369machine # [ 21.735522] k3s[844]: I0920 15:39:29.838878 844 kubelet.go:482] "Attempting to sync node with API server"1370machine # [ 21.737061] k3s[844]: I0920 15:39:29.838905 844 kubelet.go:383] "Adding static pod path" path="/var/lib/rancher/k3s/agent/pod-manifests"1371machine # [ 21.737559] k3s[844]: I0920 15:39:29.839764 844 kubelet.go:394] "Adding apiserver pod source"1372machine # [ 21.739866] k3s[844]: I0920 15:39:29.839780 844 apiserver.go:42] "Waiting for node sync before watching apiserver pods"1373machine # [ 21.741938] k3s[844]: I0920 15:39:29.845541 844 kuberuntime_manager.go:304] "Container runtime initialized" containerRuntime="containerd" version="2.2.7-k3s1" apiVersion="v1"1374machine # [ 21.745028] k3s[844]: I0920 15:39:29.848618 844 kubelet.go:945] "Not starting ClusterTrustBundle informer because we are in static kubelet mode or the ClusterTrustBundleProjection featuregate is disabled"1375machine # [ 21.745403] k3s[844]: I0920 15:39:29.849032 844 kubelet.go:972] "Not starting PodCertificateRequest manager because we are in static kubelet mode or the PodCertificateProjection feature gate is disabled"1376machine # [ 21.750947] k3s[844]: I0920 15:39:29.854567 844 server.go:1252] "Started kubelet"1377machine # [ 21.754546] k3s[844]: I0920 15:39:29.858164 844 fs_resource_analyzer.go:69] "Starting FS ResourceAnalyzer"1378machine # [ 21.768642] k3s[844]: E0920 15:39:29.872255 844 kubelet.go:1661] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"1379machine # [ 21.772266] k3s[844]: I0920 15:39:29.875832 844 server.go:182] "Starting to listen" address="0.0.0.0" port=102501380machine # [ 21.776240] k3s[844]: I0920 15:39:29.879862 844 server.go:317] "Adding debug handlers to kubelet server"1381machine # [ 21.778034] k3s[844]: I0920 15:39:29.881615 844 ratelimit.go:56] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=101382machine # [ 21.778420] k3s[844]: I0920 15:39:29.882032 844 server_v1.go:49] "podresources" method="list" useActivePods=true1383machine # [ 21.779036] k3s[844]: I0920 15:39:29.882638 844 server.go:254] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock"1384machine # [ 21.780309] k3s[844]: I0920 15:39:29.883913 844 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"1385machine # [ 21.781833] k3s[844]: I0920 15:39:29.885196 844 volume_manager.go:311] "Starting Kubelet Volume Manager"1386machine # [ 21.782611] k3s[844]: E0920 15:39:29.886228 844 kubelet_node_status.go:392] "Error getting the current node from lister" err="node \"machine\" not found"1387machine # [ 21.786681] k3s[844]: I0920 15:39:29.890296 844 desired_state_of_world_populator.go:146] "Desired state populator starts to run"1388machine # [ 21.788528] k3s[844]: I0920 15:39:29.891292 844 reconciler.go:29] "Reconciler: start to sync state"1389machine # [ 21.789766] k3s[844]: I0920 15:39:29.893387 844 factory.go:223] Registration of the systemd container factory successfully1390machine # [ 21.790766] k3s[844]: I0920 15:39:29.894312 844 factory.go:221] Registration of the crio container factory failed: Get "http://%2Fvar%2Frun%2Fcrio%2Fcrio.sock/info": dial unix /var/run/crio/crio.sock: connect: no such file or directory1391machine # [ 21.798066] k3s[844]: I0920 15:39:29.901619 844 factory.go:223] Registration of the containerd container factory successfully1392machine # [ 21.802729] k3s[844]: E0920 15:39:29.906248 844 nodelease.go:50] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"machine\" not found" node="machine"1393machine # [ 21.844274] k3s[844]: I0920 15:39:29.947866 844 cpu_manager.go:225] "Starting" policy="none"1394machine # [ 21.844867] k3s[844]: I0920 15:39:29.948275 844 cpu_manager.go:226] "Reconciling" reconcilePeriod="10s"1395machine # [ 21.845517] k3s[844]: I0920 15:39:29.948300 844 state_mem.go:41] "Initialized" logger="CPUManager state checkpoint.CPUManager state memory"1396machine # [ 21.849703] k3s[844]: I0920 15:39:29.953305 844 policy_none.go:50] "Start"1397machine # [ 21.849993] k3s[844]: I0920 15:39:29.953334 844 memory_manager.go:187] "Starting memorymanager" policy="None"1398machine # [ 21.850542] k3s[844]: I0920 15:39:29.953351 844 state_mem.go:36] "Initializing new in-memory state store" logger="Memory Manager state checkpoint"1399machine # [ 21.858793] k3s[844]: I0920 15:39:29.961434 844 policy_none.go:44] "Start"1400machine # [ 21.870044] systemd[1]: Created slice libcontainer container kubepods.slice.1401machine # [ 21.883249] k3s[844]: I0920 15:39:29.986821 844 kubelet_network_linux.go:54] "Initialized iptables rules." protocol="IPv4"1402machine # [ 21.885095] k3s[844]: E0920 15:39:29.988696 844 kubelet_node_status.go:392] "Error getting the current node from lister" err="node \"machine\" not found"1403machine # [ 21.891178] systemd[1]: Created slice libcontainer container kubepods-burstable.slice.1404machine # [ 21.898501] k3s[844]: I0920 15:39:30.002000 844 kubelet_network_linux.go:54] "Initialized iptables rules." protocol="IPv6"1405machine # [ 21.899235] k3s[844]: I0920 15:39:30.002533 844 status_manager.go:249] "Starting to sync pod status with apiserver"1406machine # [ 21.899837] k3s[844]: I0920 15:39:30.002585 844 kubelet.go:2506] "Starting kubelet main sync loop"1407machine # [ 21.900359] k3s[844]: E0920 15:39:30.002640 844 kubelet.go:2530] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"1408machine # [ 21.911110] systemd[1]: Created slice libcontainer container kubepods-besteffort.slice.1409machine # [ 21.923934] k3s[844]: E0920 15:39:30.027546 844 manager.go:525] "Failed to read data from checkpoint" err="checkpoint is not found" checkpoint="kubelet_internal_checkpoint"1410machine # [ 21.924461] k3s[844]: I0920 15:39:30.028059 844 eviction_manager.go:194] "Eviction manager: starting control loop"1411machine # [ 21.926049] k3s[844]: I0920 15:39:30.028085 844 container_log_manager.go:146] "Initializing container log rotate workers" workers=1 monitorPeriod="10s"1412machine # [ 21.927434] k3s[844]: I0920 15:39:30.031039 844 plugin_manager.go:121] "Starting Kubelet Plugin Manager"1413machine # [ 21.936481] k3s[844]: E0920 15:39:30.040071 844 eviction_manager.go:272] "eviction manager: failed to check if we have separate container filesystem. Ignoring." err="no imagefs label for configured runtime"1414machine # [ 21.936766] k3s[844]: E0920 15:39:30.040111 844 eviction_manager.go:297] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"machine\" not found"1415machine # [ 21.963772] k3s[844]: I0920 15:39:30.066744 844 controllermanager.go:627] "Warning: controller is disabled" controller="selinux-warning-controller"1416machine # [ 22.026696] k3s[844]: I0920 15:39:30.130276 844 kubelet_node_status.go:74] "Attempting to register node" node="machine"1417machine # [ 22.036276] k3s[844]: I0920 15:39:30.139878 844 kubelet_node_status.go:77] "Successfully registered node" node="machine"1418machine # [ 22.036581] k3s[844]: E0920 15:39:30.139908 844 kubelet_node_status.go:474] "Error updating node status, will retry" err="error getting node \"machine\": node \"machine\" not found"1419machine # [ 22.055791] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Annotations and labels have been set successfully on node: machine"1420machine # [ 22.056874] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Starting flannel with backend vxlan"1421machine # [ 22.087074] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller"1422machine # [ 22.088789] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Creating deploy event broadcaster"1423machine # [ 22.092452] k3s[844]: I0920 15:39:30.196063 844 controller.go:667] quota admission added evaluator for: addons.k3s.cattle.io1424machine # [ 22.099053] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Creating helm-controller event broadcaster"1425machine # [ 22.099353] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Starting /v1, Kind=Node controller"1426machine # [ 22.109332] k3s[844]: time="2026-09-20T15:39: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/ccm.yaml\"" object=kube-system/ccm reason=ApplyingManifest type=Normal1427machine # [ 22.146048] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Labels and annotations have been set successfully on node: machine"1428machine # [ 22.154281] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Cluster dns configmap has been set successfully"1429machine # [ 22.173304] k3s[844]: I0920 15:39:30.276837 844 kubelet_node_status.go:427] "Fast updating node status as it just became ready"1430machine # [ 22.452803] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Imported docker.io/library/niks3-server:1.4.0-x86_64-linux"1431machine # [ 22.457044] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Tagged docker.io/library/niks3-server@sha256:39648c5f69a101fef9bcd30a07ca4529f041f53ae3445a438e568e232fc21d21"1432machine # [ 22.492445] k3s[844]: time="2026-09-20T15:39:30Z" level=info msg="Imported 1 images from /var/lib/rancher/k3s/agent/images/niks3-server.tar in 841.426215ms"1433machine # Error from server (NotFound): namespaces "niks3" not found1434machine # [ 22.671362] k3s[844]: time="2026-09-20T15:39: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/ccm.yaml\"" object=kube-system/ccm reason=AppliedManifest type=Normal1435machine # [ 22.690637] k3s[844]: time="2026-09-20T15:39: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/ci.yaml\"" object=kube-system/ci reason=ApplyingManifest type=Normal1436machine # [ 22.737571] k3s[844]: I0920 15:39:30.841044 844 apiserver.go:52] "Watching apiserver"1437machine # [ 22.782697] k3s[844]: I0920 15:39:30.886171 844 server.go:218] "Successfully retrieved NodeIPs" NodeIPs=["10.0.2.15","fec0::d975:31c3:299f:e85"]1438machine # [ 22.786725] k3s[844]: E0920 15:39:30.886282 844 server.go:255] "Kube-proxy configuration may be incomplete or incorrect" err="nodePortAddresses is unset; NodePort connections will be accepted on all local IPs. Consider using `--nodeport-addresses primary`"1439machine # [ 22.811352] k3s[844]: I0920 15:39:30.914882 844 server.go:264] "kube-proxy running in dual-stack mode" primary ipFamily="IPv4"1440machine # [ 22.814883] k3s[844]: I0920 15:39:30.914947 844 server_linux.go:136] "Using iptables Proxier"1441machine # [ 22.833474] k3s[844]: I0920 15:39:30.937032 844 proxier.go:242] "Setting route_localnet=1 to allow node-ports on localhost; to change this either disable iptables.localhostNodePorts (--iptables-localhost-nodeports) or set nodePortAddresses (--nodeport-addresses) to filter loopback addresses" ipFamily="IPv4"1442machine # [ 22.845763] k3s[844]: I0920 15:39:30.948789 844 server.go:529] "Version info" version="v1.35.8+k3s1"1443machine # [ 22.847021] k3s[844]: I0920 15:39:30.948818 844 server.go:531] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1444machine # [ 22.859107] k3s[844]: I0920 15:39:30.962691 844 config.go:200] "Starting service config controller"1445machine # [ 22.860386] k3s[844]: I0920 15:39:30.962720 844 shared_informer.go:349] "Waiting for caches to sync" controller="service config"1446machine # [ 22.864050] k3s[844]: I0920 15:39:30.962793 844 config.go:106] "Starting endpoint slice config controller"1447machine # [ 22.865289] k3s[844]: I0920 15:39:30.962809 844 shared_informer.go:349] "Waiting for caches to sync" controller="endpoint slice config"1448machine # [ 22.866724] k3s[844]: I0920 15:39:30.962847 844 config.go:403] "Starting serviceCIDR config controller"1449machine # [ 22.867890] k3s[844]: I0920 15:39:30.962859 844 shared_informer.go:349] "Waiting for caches to sync" controller="serviceCIDR config"1450machine # [ 22.869329] k3s[844]: I0920 15:39:30.963406 844 config.go:309] "Starting node config controller"1451machine # [ 22.870431] k3s[844]: I0920 15:39:30.963421 844 shared_informer.go:349] "Waiting for caches to sync" controller="node config"1452machine # [ 22.871795] k3s[844]: I0920 15:39:30.963432 844 shared_informer.go:356] "Caches are synced" controller="node config"1453machine # [ 22.877028] k3s[844]: I0920 15:39:30.980612 844 controllermanager.go:627] "Warning: controller is disabled" controller="service-lb-controller"1454machine # [ 22.878653] k3s[844]: I0920 15:39:30.982281 844 controllermanager.go:627] "Warning: controller is disabled" controller="node-route-controller"1455machine # [ 22.884562] k3s[844]: time="2026-09-20T15:39: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/ci.yaml\"" object=kube-system/ci reason=AppliedManifest type=Normal1456machine # [ 22.888247] k3s[844]: I0920 15:39:30.991835 844 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world"1457machine # [ 22.898403] k3s[844]: time="2026-09-20T15:39: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/coredns.yaml\"" object=kube-system/coredns reason=ApplyingManifest type=Normal1458machine # [ 23.060187] k3s[844]: I0920 15:39:31.163024 844 shared_informer.go:356] "Caches are synced" controller="endpoint slice config"1459machine # [ 23.060889] k3s[844]: I0920 15:39:31.163115 844 shared_informer.go:356] "Caches are synced" controller="serviceCIDR config"1460machine # [ 23.062682] k3s[844]: I0920 15:39:31.163291 844 shared_informer.go:356] "Caches are synced" controller="service config"1461machine # [ 23.328278] k3s[844]: time="2026-09-20T15:39:31Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller"1462machine # [ 23.334676] k3s[844]: time="2026-09-20T15:39:31Z" level=info msg="Starting batch/v1, Kind=Job controller"1463machine # [ 23.335790] k3s[844]: time="2026-09-20T15:39:31Z" level=info msg="Starting /v1, Kind=Secret controller"1464machine # [ 23.336201] k3s[844]: time="2026-09-20T15:39:31Z" level=info msg="Starting /v1, Kind=ConfigMap controller"1465machine # [ 23.336618] k3s[844]: time="2026-09-20T15:39:31Z" level=info msg="Starting /v1, Kind=ServiceAccount controller"1466machine # [ 23.341834] k3s[844]: time="2026-09-20T15:39:31Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller"1467machine # [ 23.343163] k3s[844]: time="2026-09-20T15:39:31Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller"1468machine # [ 23.469609] k3s[844]: I0920 15:39:31.573193 844 controller.go:667] quota admission added evaluator for: deployments.apps1469machine # Error from server (NotFound): namespaces "niks3" not found1470machine # [ 23.822796] k3s[844]: I0920 15:39:31.925690 844 serving.go:392] Generated self-signed cert in-memory1471machine # [ 23.910274] k3s[844]: I0920 15:39:32.013808 844 serving.go:392] Generated self-signed cert in-memory1472machine # [ 23.978169] k3s[844]: I0920 15:39:32.081117 844 range_allocator.go:113] "No Secondary Service CIDR provided. Skipping filtering out secondary service addresses" logger="node-ipam-controller"1473machine # [ 23.988511] k3s[844]: I0920 15:39:32.089228 844 controllermanager.go:160] Version: v1.35.8+k3s11474machine # [ 23.991332] k3s[844]: I0920 15:39:32.092038 844 secure_serving.go:211] Serving securely on 127.0.0.1:102581475machine # [ 23.994419] k3s[844]: I0920 15:39:32.092307 844 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1476machine # [ 23.997834] k3s[844]: I0920 15:39:32.092327 844 shared_informer.go:370] "Waiting for caches to sync"1477machine # [ 24.000680] k3s[844]: I0920 15:39:32.092361 844 tlsconfig.go:243] "Starting DynamicServingCertificateController"1478machine # [ 24.003867] k3s[844]: I0920 15:39:32.092573 844 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1479machine # [ 24.008529] k3s[844]: I0920 15:39:32.092591 844 shared_informer.go:370] "Waiting for caches to sync"1480machine # [ 24.013215] k3s[844]: I0920 15:39:32.092617 844 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1481machine # [ 24.017686] k3s[844]: I0920 15:39:32.092631 844 shared_informer.go:370] "Waiting for caches to sync"1482machine # [ 24.020037] k3s[844]: time="2026-09-20T15:39:32Z" level=info msg="Creating service-lb-controller event broadcaster"1483machine # [ 24.030141] k3s[844]: I0920 15:39:32.133708 844 alloc.go:329] "allocated clusterIPs" service="kube-system/kube-dns" clusterIPs={"IPv4":"10.43.0.10"}1484machine # [ 24.033514] k3s[844]: time="2026-09-20T15:39:32Z" 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=Normal1485machine # [ 24.090294] k3s[844]: I0920 15:39:32.192808 844 shared_informer.go:377] "Caches are synced"1486machine # [ 24.091453] k3s[844]: I0920 15:39:32.192817 844 shared_informer.go:377] "Caches are synced"1487machine # [ 24.092606] k3s[844]: I0920 15:39:32.192846 844 shared_informer.go:377] "Caches are synced"1488machine # [ 24.162489] k3s[844]: time="2026-09-20T15:39:32Z" level=info msg="Starting /v1, Kind=Node controller"1489machine # [ 24.167452] k3s[844]: time="2026-09-20T15:39:32Z" level=info msg="Starting /v1, Kind=Pod controller"1490machine # [ 24.171838] k3s[844]: time="2026-09-20T15:39:32Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller"1491machine # [ 24.177556] k3s[844]: time="2026-09-20T15:39:32Z" level=info msg="Starting discovery.k8s.io/v1, Kind=EndpointSlice controller"1492machine # [ 24.180321] k3s[844]: I0920 15:39:32.279898 844 controllermanager.go:329] Started "cloud-node-lifecycle-controller"1493machine # [ 24.182885] k3s[844]: I0920 15:39:32.280270 844 controllermanager.go:329] Started "service-lb-controller"1494machine # [ 24.185301] k3s[844]: W0920 15:39:32.280284 844 controllermanager.go:306] "node-route-controller" is disabled1495machine # [ 24.186534] k3s[844]: I0920 15:39:32.280520 844 controllermanager.go:329] Started "cloud-node-controller"1496machine # [ 24.187703] k3s[844]: I0920 15:39:32.280602 844 node_lifecycle_controller.go:112] Sending events to api server1497machine # [ 24.188941] k3s[844]: I0920 15:39:32.280969 844 controller.go:235] Starting service controller1498machine # [ 24.190048] k3s[844]: I0920 15:39:32.281000 844 shared_informer.go:370] "Waiting for caches to sync"1499machine # [ 24.191192] k3s[844]: I0920 15:39:32.281045 844 node_controller.go:176] Sending events to api server.1500machine # [ 24.192368] k3s[844]: I0920 15:39:32.281108 844 node_controller.go:185] Waiting for informer caches to sync1501machine # [ 24.428758] k3s[844]: I0920 15:39:32.532118 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="resourceclaimtemplates.resource.k8s.io"1502machine # [ 24.434333] k3s[844]: I0920 15:39:32.532280 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="controllerrevisions.apps"1503machine # [ 24.439325] k3s[844]: I0920 15:39:32.532332 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpointslices.discovery.k8s.io"1504machine # [ 24.444561] k3s[844]: I0920 15:39:32.532452 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="deployments.apps"1505machine # [ 24.449359] k3s[844]: I0920 15:39:32.532517 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="jobs.batch"1506machine # [ 24.454073] k3s[844]: I0920 15:39:32.532579 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="rolebindings.rbac.authorization.k8s.io"1507machine # [ 24.459458] k3s[844]: I0920 15:39:32.532634 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="podtemplates"1508machine # [ 24.464187] k3s[844]: I0920 15:39:32.532808 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="horizontalpodautoscalers.autoscaling"1509machine # [ 24.469512] k3s[844]: I0920 15:39:32.532860 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="cronjobs.batch"1510machine # [ 24.473667] k3s[844]: I0920 15:39:32.532925 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmcharts.helm.cattle.io"1511machine # [ 24.477687] k3s[844]: I0920 15:39:32.532976 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="serviceaccounts"1512machine # [ 24.481503] k3s[844]: I0920 15:39:32.533051 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="replicasets.apps"1513machine # [ 24.485367] k3s[844]: I0920 15:39:32.533103 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="csistoragecapacities.storage.k8s.io"1514machine # [ 24.489552] k3s[844]: I0920 15:39:32.533179 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="helmchartconfigs.helm.cattle.io"1515machine # [ 24.491999] k3s[844]: I0920 15:39:32.533228 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="limitranges"1516machine # [ 24.494026] k3s[844]: I0920 15:39:32.533273 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="daemonsets.apps"1517machine # [ 24.494316] k3s[844]: I0920 15:39:32.533320 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="statefulsets.apps"1518machine # [ 24.494743] k3s[844]: I0920 15:39:32.533370 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="poddisruptionbudgets.policy"1519machine # [ 24.495366] k3s[844]: I0920 15:39:32.533417 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="leases.coordination.k8s.io"1520machine # [ 24.495798] k3s[844]: I0920 15:39:32.533465 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="addons.k3s.cattle.io"1521machine # [ 24.496427] k3s[844]: I0920 15:39:32.533650 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="networkpolicies.networking.k8s.io"1522machine # [ 24.496853] k3s[844]: I0920 15:39:32.533768 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="roles.rbac.authorization.k8s.io"1523machine # [ 24.497506] k3s[844]: I0920 15:39:32.533829 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="endpoints"1524machine # [ 24.497902] k3s[844]: I0920 15:39:32.533878 844 resource_quota_monitor.go:229] "QuotaMonitor created object count evaluator" logger="resourcequota-controller" resource="ingresses.networking.k8s.io"1525machine # [ 24.578510] k3s[844]: I0920 15:39:32.681800 844 shared_informer.go:377] "Caches are synced"1526machine # [ 24.578696] k3s[844]: I0920 15:39:32.681839 844 node_controller.go:429] Initializing node machine with cloud provider1527machine # [ 24.604062] k3s[844]: I0920 15:39:32.706271 844 server.go:173] "Starting Kubernetes Scheduler" version="v1.35.8+k3s1"1528machine # [ 24.604204] k3s[844]: I0920 15:39:32.706294 844 server.go:175] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""1529machine # [ 24.607657] k3s[844]: I0920 15:39:32.711273 844 secure_serving.go:211] Serving securely on 127.0.0.1:102591530machine # [ 24.608937] k3s[844]: time="2026-09-20T15:39:32Z" level=info msg="Synced coredns NodeHosts entries for machine"1531machine # [ 24.611056] k3s[844]: I0920 15:39:32.713924 844 requestheader_controller.go:180] Starting RequestHeaderAuthRequestController1532machine # [ 24.611736] k3s[844]: I0920 15:39:32.713948 844 shared_informer.go:370] "Waiting for caches to sync"1533machine # [ 24.615119] k3s[844]: I0920 15:39:32.713985 844 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"1534machine # [ 24.615724] k3s[844]: I0920 15:39:32.714076 844 tlsconfig.go:243] "Starting DynamicServingCertificateController"1535machine # [ 24.616338] k3s[844]: I0920 15:39:32.717919 844 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file"1536machine # [ 24.619083] k3s[844]: I0920 15:39:32.717936 844 shared_informer.go:370] "Waiting for caches to sync"1537machine # [ 24.619297] k3s[844]: I0920 15:39:32.717971 844 configmap_cafile_content.go:205] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file"1538machine # [ 24.619737] k3s[844]: I0920 15:39:32.717984 844 shared_informer.go:370] "Waiting for caches to sync"1539machine # [ 24.631258] k3s[844]: I0920 15:39:32.734857 844 node_controller.go:474] Successfully initialized node machine with cloud provider1540machine # [ 24.634304] k3s[844]: I0920 15:39:32.737904 844 event.go:389] "Event occurred" object="machine" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="Synced" message="Node synced successfully"1541machine # [ 24.710579] k3s[844]: I0920 15:39:32.814041 844 shared_informer.go:377] "Caches are synced"1542machine # [ 24.715085] k3s[844]: I0920 15:39:32.818633 844 shared_informer.go:377] "Caches are synced"1543machine # [ 24.716804] k3s[844]: I0920 15:39:32.819548 844 shared_informer.go:377] "Caches are synced"1544machine # [ 24.724100] k3s[844]: I0920 15:39:32.827609 844 controllermanager.go:627] "Warning: controller is disabled" controller="bootstrap-signer-controller"1545machine # [ 24.724821] k3s[844]: I0920 15:39:32.827731 844 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller" requiredFeatureGates=["ClusterTrustBundle"]1546machine # [ 24.726597] k3s[844]: I0920 15:39:32.827769 844 controllermanager.go:579] "Warning: skipping controller" controller="kube-apiserver-serving-clustertrustbundle-publisher-controller"1547machine # Error from server (NotFound): namespaces "niks3" not found1548machine # [ 24.975159] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1549machine # [ 24.987069] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1550machine # [ 25.075053] k3s[844]: I0920 15:39:33.178442 844 controller.go:667] quota admission added evaluator for: helmcharts.helm.cattle.io1551machine # [ 25.087127] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1552machine # [ 25.108607] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1553machine # [ 25.221157] k3s[844]: I0920 15:39:33.324325 844 controller_descriptor.go:99] "Controller is disabled by a feature gate" controller="storageversion-garbage-collector-controller" requiredFeatureGates=["APIServerIdentity","StorageVersionAPI"]1554machine # [ 25.227457] k3s[844]: I0920 15:39:33.324380 844 controllermanager.go:579] "Warning: skipping controller" controller="storageversion-garbage-collector-controller"1555machine # [ 25.231731] k3s[844]: I0920 15:39:33.324410 844 controllermanager.go:579] "Warning: skipping controller" controller="storage-version-migrator-controller"1556machine # [ 25.237195] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1557machine # [ 25.250185] k3s[844]: I0920 15:39:33.353735 844 pvc_protection_controller.go:166] "Starting PVC protection controller"1558machine # [ 25.253225] k3s[844]: I0920 15:39:33.356819 844 shared_informer.go:370] "Waiting for caches to sync"1559machine # [ 25.263832] k3s[844]: I0920 15:39:33.367394 844 shared_informer.go:370] "Waiting for caches to sync"1560machine # [ 25.265969] k3s[844]: I0920 15:39:33.369592 844 replica_set.go:241] "Starting controller" name="replicationcontroller"1561machine # [ 25.267344] k3s[844]: I0920 15:39:33.370974 844 shared_informer.go:370] "Waiting for caches to sync"1562machine # [ 25.268629] k3s[844]: I0920 15:39:33.372254 844 job_controller.go:254] "Starting job controller"1563machine # [ 25.269785] k3s[844]: I0920 15:39:33.373416 844 shared_informer.go:370] "Waiting for caches to sync"1564machine # [ 25.272109] k3s[844]: I0920 15:39:33.374633 844 ttl_controller.go:127] "Starting TTL controller"1565machine # [ 25.273236] k3s[844]: I0920 15:39:33.374648 844 shared_informer.go:370] "Waiting for caches to sync"1566machine # [ 25.274366] k3s[844]: I0920 15:39:33.374708 844 expand_controller.go:328] "Starting expand controller"1567machine # [ 25.275508] k3s[844]: I0920 15:39:33.374724 844 shared_informer.go:370] "Waiting for caches to sync"1568machine # [ 25.276647] k3s[844]: I0920 15:39:33.374752 844 pv_protection_controller.go:81] "Starting PV protection controller"1569machine # [ 25.277915] k3s[844]: I0920 15:39:33.374764 844 shared_informer.go:370] "Waiting for caches to sync"1570machine # [ 25.279082] k3s[844]: I0920 15:39:33.374850 844 endpointslice_controller.go:283] "Starting endpoint slice controller"1571machine # [ 25.280370] k3s[844]: I0920 15:39:33.374862 844 shared_informer.go:370] "Waiting for caches to sync"1572machine # [ 25.281507] k3s[844]: I0920 15:39:33.374903 844 controller.go:174] "Starting ephemeral volume controller"1573machine # [ 25.282679] k3s[844]: I0920 15:39:33.374915 844 shared_informer.go:370] "Waiting for caches to sync"1574machine # [ 25.283834] k3s[844]: I0920 15:39:33.374954 844 taint_eviction.go:283] "Starting" controller="taint-eviction-controller"1575machine # [ 25.285147] k3s[844]: I0920 15:39:33.375006 844 taint_eviction.go:288] "Sending events to API server"1576machine # [ 25.286329] k3s[844]: I0920 15:39:33.375016 844 shared_informer.go:370] "Waiting for caches to sync"1577machine # [ 25.287468] k3s[844]: I0920 15:39:33.375080 844 servicecidrs_controller.go:136] "Starting" controller="service-cidr-controller"1578machine # [ 25.288924] k3s[844]: I0920 15:39:33.375092 844 shared_informer.go:370] "Waiting for caches to sync"1579machine # [ 25.290083] k3s[844]: I0920 15:39:33.375151 844 daemon_controller.go:309] "Starting daemon sets controller"1580machine # [ 25.291280] k3s[844]: I0920 15:39:33.375162 844 shared_informer.go:370] "Waiting for caches to sync"1581machine # [ 25.292409] k3s[844]: I0920 15:39:33.375197 844 certificate_controller.go:120] "Starting certificate controller" name="csrapproving"1582machine # [ 25.293826] k3s[844]: I0920 15:39:33.375209 844 shared_informer.go:370] "Waiting for caches to sync"1583machine # [ 25.294956] k3s[844]: I0920 15:39:33.375259 844 node_lifecycle_controller.go:453] "Sending events to api server"1584machine # [ 25.296207] k3s[844]: I0920 15:39:33.375283 844 node_lifecycle_controller.go:460] "Starting node controller"1585machine # [ 25.297444] k3s[844]: I0920 15:39:33.375293 844 shared_informer.go:370] "Waiting for caches to sync"1586machine # [ 25.298570] k3s[844]: I0920 15:39:33.375363 844 attach_detach_controller.go:335] "Starting attach detach controller"1587machine # [ 25.299853] k3s[844]: I0920 15:39:33.375376 844 shared_informer.go:370] "Waiting for caches to sync"1588machine # [ 25.300991] k3s[844]: I0920 15:39:33.375405 844 vac_protection_controller.go:206] "Starting VAC protection controller"1589machine # [ 25.302330] k3s[844]: I0920 15:39:33.375416 844 shared_informer.go:370] "Waiting for caches to sync"1590machine # [ 25.305093] k3s[844]: I0920 15:39:33.375488 844 controller.go:423] "Starting resource claim controller"1591machine # [ 25.306273] k3s[844]: I0920 15:39:33.375501 844 shared_informer.go:370] "Waiting for caches to sync"1592machine # [ 25.307409] k3s[844]: I0920 15:39:33.375537 844 disruption.go:458] "Sending events to api server."1593machine # [ 25.308536] k3s[844]: I0920 15:39:33.375569 844 disruption.go:465] "Starting disruption controller"1594machine # [ 25.309666] k3s[844]: I0920 15:39:33.375579 844 shared_informer.go:370] "Waiting for caches to sync"1595machine # [ 25.310801] k3s[844]: I0920 15:39:33.375607 844 ttlafterfinished_controller.go:112] "Starting TTL after finished controller"1596machine # [ 25.312164] k3s[844]: I0920 15:39:33.375620 844 shared_informer.go:370] "Waiting for caches to sync"1597machine # [ 25.313376] k3s[844]: I0920 15:39:33.407319 844 legacy_serviceaccount_token_cleaner.go:103] "Starting legacy service account token cleaner controller"1598machine # [ 25.314951] k3s[844]: I0920 15:39:33.407347 844 shared_informer.go:370] "Waiting for caches to sync"1599machine # [ 25.316097] k3s[844]: I0920 15:39:33.407393 844 gc_controller.go:98] "Starting GC controller"1600machine # [ 25.317171] k3s[844]: I0920 15:39:33.407411 844 shared_informer.go:370] "Waiting for caches to sync"1601machine # [ 25.318339] k3s[844]: I0920 15:39:33.375653 844 publisher.go:107] "Starting root CA cert publisher controller"1602machine # [ 25.319564] k3s[844]: I0920 15:39:33.407453 844 shared_informer.go:370] "Waiting for caches to sync"1603machine # [ 25.320705] k3s[844]: I0920 15:39:33.407831 844 stateful_set.go:180] "Starting stateful set controller"1604machine # [ 25.321877] k3s[844]: I0920 15:39:33.407847 844 shared_informer.go:370] "Waiting for caches to sync"1605machine # [ 25.323028] k3s[844]: I0920 15:39:33.407933 844 cronjob_controllerv2.go:143] "Starting cronjob controller v2"1606machine # [ 25.324243] k3s[844]: I0920 15:39:33.407945 844 shared_informer.go:370] "Waiting for caches to sync"1607machine # [ 25.325375] k3s[844]: I0920 15:39:33.407993 844 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-legacy-unknown"1608machine # [ 25.326913] k3s[844]: I0920 15:39:33.408007 844 shared_informer.go:370] "Waiting for caches to sync"1609machine # [ 25.328070] k3s[844]: I0920 15:39:33.408036 844 tokencleaner.go:117] "Starting token cleaner controller"1610machine # [ 25.329231] k3s[844]: I0920 15:39:33.408048 844 shared_informer.go:370] "Waiting for caches to sync"1611machine # [ 25.330378] k3s[844]: I0920 15:39:33.408141 844 endpoints_controller.go:193] "Starting endpoint controller"1612machine # [ 25.331581] k3s[844]: I0920 15:39:33.408153 844 shared_informer.go:370] "Waiting for caches to sync"1613machine # [ 25.335094] k3s[844]: I0920 15:39:33.408188 844 serviceaccounts_controller.go:117] "Starting service account controller"1614machine # [ 25.336455] k3s[844]: I0920 15:39:33.408200 844 shared_informer.go:370] "Waiting for caches to sync"1615machine # [ 25.337600] k3s[844]: I0920 15:39:33.408261 844 deployment_controller.go:172] "Starting controller" controller="deployment"1616machine # [ 25.338954] k3s[844]: I0920 15:39:33.408274 844 shared_informer.go:370] "Waiting for caches to sync"1617machine # [ 25.340115] k3s[844]: I0920 15:39:33.408336 844 replica_set.go:241] "Starting controller" name="replicaset"1618machine # [ 25.341348] k3s[844]: I0920 15:39:33.408347 844 shared_informer.go:370] "Waiting for caches to sync"1619machine # [ 25.342478] k3s[844]: I0920 15:39:33.408421 844 node_ipam_controller.go:142] "Starting ipam controller"1620machine # [ 25.343639] k3s[844]: I0920 15:39:33.408435 844 shared_informer.go:370] "Waiting for caches to sync"1621machine # [ 25.344767] k3s[844]: I0920 15:39:33.408498 844 pv_controller_base.go:307] "Starting persistent volume controller"1622machine # [ 25.346034] k3s[844]: I0920 15:39:33.408510 844 shared_informer.go:370] "Waiting for caches to sync"1623machine # [ 25.347170] k3s[844]: I0920 15:39:33.408538 844 shared_informer.go:370] "Waiting for caches to sync"1624machine # [ 25.348342] k3s[844]: I0920 15:39:33.408599 844 endpointslicemirroring_controller.go:226] "Starting EndpointSliceMirroring controller"1625machine # [ 25.349771] k3s[844]: I0920 15:39:33.408611 844 shared_informer.go:370] "Waiting for caches to sync"1626machine # [ 25.350955] k3s[844]: I0920 15:39:33.436155 844 controller.go:667] quota admission added evaluator for: jobs.batch1627machine # [ 25.352223] k3s[844]: I0920 15:39:33.436429 844 namespace_controller.go:202] "Starting namespace controller"1628machine # [ 25.353457] k3s[844]: I0920 15:39:33.436456 844 shared_informer.go:370] "Waiting for caches to sync"1629machine # [ 25.354591] k3s[844]: I0920 15:39:33.436509 844 cleaner.go:83] "Starting CSR cleaner controller"1630machine # [ 25.355688] k3s[844]: I0920 15:39:33.436577 844 horizontal.go:204] "Starting HPA controller"1631machine # [ 25.356769] k3s[844]: I0920 15:39:33.436591 844 shared_informer.go:370] "Waiting for caches to sync"1632machine # [ 25.357911] k3s[844]: I0920 15:39:33.436621 844 clusterroleaggregation_controller.go:194] "Starting ClusterRoleAggregator controller"1633machine # [ 25.359383] k3s[844]: I0920 15:39:33.436633 844 shared_informer.go:370] "Waiting for caches to sync"1634machine # [ 25.360522] k3s[844]: I0920 15:39:33.438198 844 garbagecollector.go:141] "Starting controller" controller="garbagecollector"1635machine # [ 25.361909] k3s[844]: I0920 15:39:33.438229 844 shared_informer.go:370] "Waiting for caches to sync"1636machine # [ 25.363061] k3s[844]: I0920 15:39:33.438283 844 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-serving"1637machine # [ 25.364638] k3s[844]: I0920 15:39:33.438296 844 shared_informer.go:370] "Waiting for caches to sync"1638machine # [ 25.365767] k3s[844]: I0920 15:39:33.438328 844 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kubelet-client"1639machine # [ 25.367334] k3s[844]: I0920 15:39:33.438340 844 shared_informer.go:370] "Waiting for caches to sync"1640machine # [ 25.368476] k3s[844]: I0920 15:39:33.438375 844 certificate_controller.go:120] "Starting certificate controller" name="csrsigning-kube-apiserver-client"1641machine # [ 25.370088] k3s[844]: I0920 15:39:33.438387 844 shared_informer.go:370] "Waiting for caches to sync"1642machine # [ 25.371223] k3s[844]: I0920 15:39:33.438422 844 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"1643machine # [ 25.373516] k3s[844]: I0920 15:39:33.438595 844 resource_quota_controller.go:297] "Starting resource quota controller"1644machine # [ 25.374817] k3s[844]: I0920 15:39:33.438610 844 shared_informer.go:370] "Waiting for caches to sync"1645machine # [ 25.375964] k3s[844]: I0920 15:39:33.446329 844 graph_builder.go:386] "Running" component="GraphBuilder"1646machine # [ 25.377134] k3s[844]: I0920 15:39:33.446364 844 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"1647machine # [ 25.379449] k3s[844]: I0920 15:39:33.446486 844 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"1648machine # [ 25.381704] k3s[844]: I0920 15:39:33.446546 844 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"1649machine # [ 25.383968] k3s[844]: I0920 15:39:33.446763 844 resource_quota_monitor.go:309] "QuotaMonitor running"1650machine # [ 25.385159] k3s[844]: I0920 15:39:33.464490 844 shared_informer.go:370] "Waiting for caches to sync"1651machine # [ 25.386342] k3s[844]: I0920 15:39:33.475011 844 shared_informer.go:377] "Caches are synced"1652machine # [ 25.387411] k3s[844]: I0920 15:39:33.475599 844 shared_informer.go:377] "Caches are synced"1653machine # [ 25.388469] k3s[844]: I0920 15:39:33.475654 844 shared_informer.go:377] "Caches are synced"1654machine # [ 25.389523] k3s[844]: I0920 15:39:33.477725 844 shared_informer.go:377] "Caches are synced"1655machine # [ 25.390591] k3s[844]: I0920 15:39:33.479490 844 shared_informer.go:370] "Waiting for caches to sync"1656machine # [ 25.405071] k3s[844]: I0920 15:39:33.508442 844 shared_informer.go:377] "Caches are synced"1657machine # [ 25.406199] k3s[844]: I0920 15:39:33.508701 844 shared_informer.go:377] "Caches are synced"1658machine # [ 25.409191] k3s[844]: I0920 15:39:33.508903 844 shared_informer.go:377] "Caches are synced"1659machine # [ 25.410285] k3s[844]: I0920 15:39:33.508943 844 shared_informer.go:377] "Caches are synced"1660machine # [ 25.411352] k3s[844]: I0920 15:39:33.509099 844 shared_informer.go:377] "Caches are synced"1661machine # [ 25.422235] k3s[844]: I0920 15:39:33.525837 844 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"1662machine # [ 25.427608] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1663machine # [ 25.433244] k3s[844]: I0920 15:39:33.536779 844 shared_informer.go:377] "Caches are synced"1664machine # [ 25.434362] k3s[844]: I0920 15:39:33.537177 844 shared_informer.go:377] "Caches are synced"1665machine # [ 25.435434] k3s[844]: I0920 15:39:33.537225 844 shared_informer.go:377] "Caches are synced"1666machine # [ 25.436500] k3s[844]: I0920 15:39:33.537789 844 shared_informer.go:377] "Caches are synced"1667machine # [ 25.437553] k3s[844]: I0920 15:39:33.537914 844 shared_informer.go:377] "Caches are synced"1668machine # [ 25.438634] k3s[844]: I0920 15:39:33.539111 844 shared_informer.go:377] "Caches are synced"1669machine # [ 25.439696] k3s[844]: I0920 15:39:33.539433 844 shared_informer.go:377] "Caches are synced"1670machine # [ 25.440752] k3s[844]: I0920 15:39:33.539465 844 shared_informer.go:377] "Caches are synced"1671machine # [ 25.441816] k3s[844]: I0920 15:39:33.539503 844 shared_informer.go:377] "Caches are synced"1672machine # [ 25.442889] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1673machine # [ 25.456648] k3s[844]: I0920 15:39:33.560231 844 shared_informer.go:377] "Caches are synced"1674machine # [ 25.461329] k3s[844]: I0920 15:39:33.564835 844 shared_informer.go:377] "Caches are synced"1675machine # [ 25.472104] k3s[844]: I0920 15:39:33.575714 844 shared_informer.go:377] "Caches are synced"1676machine # [ 25.473238] k3s[844]: I0920 15:39:33.575818 844 shared_informer.go:377] "Caches are synced"1677machine # [ 25.474320] k3s[844]: I0920 15:39:33.576249 844 shared_informer.go:377] "Caches are synced"1678machine # [ 25.475385] k3s[844]: I0920 15:39:33.576278 844 shared_informer.go:377] "Caches are synced"1679machine # [ 25.476452] k3s[844]: I0920 15:39:33.576327 844 shared_informer.go:377] "Caches are synced"1680machine # [ 25.477505] k3s[844]: I0920 15:39:33.576372 844 shared_informer.go:377] "Caches are synced"1681machine # [ 25.478553] k3s[844]: I0920 15:39:33.576556 844 shared_informer.go:377] "Caches are synced"1682machine # [ 25.479609] k3s[844]: I0920 15:39:33.576599 844 shared_informer.go:377] "Caches are synced"1683machine # [ 25.480664] k3s[844]: I0920 15:39:33.576631 844 shared_informer.go:377] "Caches are synced"1684machine # [ 25.481721] k3s[844]: I0920 15:39:33.576732 844 node_lifecycle_controller.go:1234] "Initializing eviction metric for zone" zone=""1685machine # [ 25.483122] k3s[844]: I0920 15:39:33.576805 844 node_lifecycle_controller.go:886] "Missing timestamp for Node. Assuming now as a timestamp" node="machine"1686machine # [ 25.484765] k3s[844]: I0920 15:39:33.576870 844 node_lifecycle_controller.go:1080] "Controller detected that zone is now in new state" zone="" newState="Normal"1687machine # [ 25.486493] k3s[844]: I0920 15:39:33.576911 844 shared_informer.go:377] "Caches are synced"1688machine # [ 25.487567] k3s[844]: I0920 15:39:33.577061 844 shared_informer.go:377] "Caches are synced"1689machine # [ 25.490137] k3s[844]: I0920 15:39:33.592388 844 shared_informer.go:377] "Caches are synced"1690machine # [ 25.503709] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1691machine # [ 25.506518] k3s[844]: I0920 15:39:33.607545 844 shared_informer.go:377] "Caches are synced"1692machine # [ 25.509062] k3s[844]: I0920 15:39:33.612649 844 shared_informer.go:377] "Caches are synced"1693machine # [ 25.510235] k3s[844]: I0920 15:39:33.612743 844 shared_informer.go:377] "Caches are synced"1694machine # [ 25.511324] k3s[844]: I0920 15:39:33.612779 844 shared_informer.go:377] "Caches are synced"1695machine # [ 25.512616] k3s[844]: I0920 15:39:33.613211 844 shared_informer.go:377] "Caches are synced"1696machine # [ 25.513834] k3s[844]: I0920 15:39:33.613649 844 shared_informer.go:377] "Caches are synced"1697machine # [ 25.514968] k3s[844]: I0920 15:39:33.613724 844 shared_informer.go:377] "Caches are synced"1698machine # [ 25.516157] k3s[844]: I0920 15:39:33.613761 844 range_allocator.go:177] "Sending events to api server"1699machine # [ 25.517352] k3s[844]: I0920 15:39:33.613790 844 range_allocator.go:181] "Starting range CIDR allocator"1700machine # [ 25.518507] k3s[844]: I0920 15:39:33.613801 844 shared_informer.go:370] "Waiting for caches to sync"1701machine # [ 25.519640] k3s[844]: I0920 15:39:33.613811 844 shared_informer.go:377] "Caches are synced"1702machine # [ 25.520795] k3s[844]: I0920 15:39:33.614130 844 shared_informer.go:377] "Caches are synced"1703machine # [ 25.521859] k3s[844]: I0920 15:39:33.614360 844 shared_informer.go:377] "Caches are synced"1704machine # [ 25.522911] k3s[844]: I0920 15:39:33.614403 844 shared_informer.go:377] "Caches are synced"1705machine # [ 25.528057] k3s[844]: I0920 15:39:33.631089 844 range_allocator.go:433] "Set node PodCIDR" node="machine" podCIDRs=["10.42.0.0/24"]1706machine # [ 25.571591] k3s[844]: time="2026-09-20T15:39:33Z" 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=Normal1707machine # [ 25.583461] systemd[1]: Created slice libcontainer container kubepods-burstable-podbf2a4011_595b_4564_813c_8b8c4a00034b.slice.1708machine # [ 25.608728] k3s[844]: time="2026-09-20T15:39:33Z" level=info msg="Tunnel authorizer set Kubelet Port 0.0.0.0:10250"1709machine # [ 25.747781] k3s[844]: I0920 15:39:33.851092 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-tmp\") pod \"helm-install-niks3-gs2wp\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") " pod="kube-system/helm-install-niks3-gs2wp"1710machine # [ 25.756804] k3s[844]: I0920 15:39:33.851213 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"values\" (UniqueName: \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-values\") pod \"helm-install-niks3-gs2wp\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") " pod="kube-system/helm-install-niks3-gs2wp"1711machine # [ 25.766100] k3s[844]: I0920 15:39:33.851276 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"content\" (UniqueName: \"kubernetes.io/configmap/bf2a4011-595b-4564-813c-8b8c4a00034b-content\") pod \"helm-install-niks3-gs2wp\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") " pod="kube-system/helm-install-niks3-gs2wp"1712machine # [ 25.775561] k3s[844]: I0920 15:39:33.851332 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-sgc5d\" (UniqueName: \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-kube-api-access-sgc5d\") pod \"helm-install-niks3-gs2wp\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") " pod="kube-system/helm-install-niks3-gs2wp"1713machine # [ 25.785304] k3s[844]: I0920 15:39:33.851390 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-helm\") pod \"helm-install-niks3-gs2wp\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") " pod="kube-system/helm-install-niks3-gs2wp"1714machine # [ 25.793250] k3s[844]: I0920 15:39:33.851444 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-cache\") pod \"helm-install-niks3-gs2wp\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") " pod="kube-system/helm-install-niks3-gs2wp"1715machine # [ 25.793763] k3s[844]: I0920 15:39:33.851511 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-config\") pod \"helm-install-niks3-gs2wp\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") " pod="kube-system/helm-install-niks3-gs2wp"1716machine # [ 25.985330] k3s[844]: E0920 15:39:34.088211 844 projected.go:291] Couldn't get configMap kube-system/kube-root-ca.crt: configmap "kube-root-ca.crt" not found1717machine # [ 25.986083] k3s[844]: E0920 15:39:34.089181 844 projected.go:196] Error preparing data for projected volume kube-api-access-sgc5d for pod kube-system/helm-install-niks3-gs2wp: configmap "kube-root-ca.crt" not found1718machine # [ 25.986687] k3s[844]: E0920 15:39:34.089274 844 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-kube-api-access-sgc5d podName:bf2a4011-595b-4564-813c-8b8c4a00034b nodeName:}" failed. No retries permitted until 2026-09-20 15:39:34.589253939 +0000 UTC m=+11.650633949 (durationBeforeRetry 500ms). Error: MountVolume.SetUp failed for volume "kube-api-access-sgc5d" (UniqueName: "kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-kube-api-access-sgc5d") pod "helm-install-niks3-gs2wp" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b") : configmap "kube-root-ca.crt" not found1719machine # [ 25.996068] k3s[844]: time="2026-09-20T15:39:34Z" 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=Normal1720machine # [ 26.017984] k3s[844]: time="2026-09-20T15:39:34Z" level=info msg="Event occurred" apiVersion= fieldPath= kind=Node logger=k3s message="Deferred node password secret validation complete" object=machine reason=NodePasswordValidationComplete type=Normal1721machine # [ 26.032445] k3s[844]: I0920 15:39:34.136051 844 controller.go:667] quota admission added evaluator for: replicasets.apps1722machine # [ 26.123477] k3s[844]: time="2026-09-20T15:39:34Z" level=info msg="Adding node OwnerReference to node-password secret machine.node-password.k3s"1723machine # [ 26.126986] k3s[844]: time="2026-09-20T15:39:34Z" level=info msg="Flannel found PodCIDR assigned for node machine"1724machine # [ 26.135132] k3s[844]: time="2026-09-20T15:39:34Z" level=info msg="The interface eth0 with ipv4 address 10.0.2.15 will be used by flannel"1725machine # [ 26.137203] k3s[844]: I0920 15:39:34.240748 844 kube.go:139] Waiting 10m0s for node controller to sync1726machine # [ 26.137464] k3s[844]: I0920 15:39:34.240835 844 kube.go:537] Starting kube subnet manager1727machine # [ 26.171632] k3s[844]: I0920 15:39:34.274960 844 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161728machine # [ 26.177616] k3s[844]: I0920 15:39:34.281234 844 cidrallocator.go:278] updated ClusterIP allocator for Service CIDR 10.43.0.0/161729machine # Error from server (NotFound): namespaces "niks3" not found1730machine # [ 26.440238] k3s[844]: I0920 15:39:34.542948 844 shared_informer.go:377] "Caches are synced"1731machine # [ 26.440833] k3s[844]: I0920 15:39:34.542994 844 garbagecollector.go:166] "Garbage collector: all resource monitors have synced"1732machine # [ 26.441531] k3s[844]: I0920 15:39:34.543019 844 garbagecollector.go:169] "Proceeding to collect garbage"1733machine # [ 26.460966] systemd[1]: Created slice libcontainer container kubepods-burstable-pod4e71e95c_229d_424f_98ae_a7acf7ff2a63.slice.1734machine # [ 26.476441] k3s[844]: I0920 15:39:34.579943 844 shared_informer.go:377] "Caches are synced"1735machine # [ 26.571390] k3s[844]: I0920 15:39:34.674918 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"config-volume\" (UniqueName: \"kubernetes.io/configmap/4e71e95c-229d-424f-98ae-a7acf7ff2a63-config-volume\") pod \"coredns-c5fdd76cf-r9kxv\" (UID: \"4e71e95c-229d-424f-98ae-a7acf7ff2a63\") " pod="kube-system/coredns-c5fdd76cf-r9kxv"1736machine # [ 26.575431] k3s[844]: I0920 15:39:34.675011 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-tp89t\" (UniqueName: \"kubernetes.io/projected/4e71e95c-229d-424f-98ae-a7acf7ff2a63-kube-api-access-tp89t\") pod \"coredns-c5fdd76cf-r9kxv\" (UID: \"4e71e95c-229d-424f-98ae-a7acf7ff2a63\") " pod="kube-system/coredns-c5fdd76cf-r9kxv"1737machine # [ 26.579362] k3s[844]: I0920 15:39:34.675126 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"custom-config-volume\" (UniqueName: \"kubernetes.io/configmap/4e71e95c-229d-424f-98ae-a7acf7ff2a63-custom-config-volume\") pod \"coredns-c5fdd76cf-r9kxv\" (UID: \"4e71e95c-229d-424f-98ae-a7acf7ff2a63\") " pod="kube-system/coredns-c5fdd76cf-r9kxv"1738machine # [ 26.874112] systemd[1]: run-netns-cni\x2d00af16aa\x2dd6ab\x2d186e\x2dfc3d\x2db9af9754e393.mount: Deactivated successfully.1739machine # [ 26.877910] k3s[844]: E0920 15:39:34.981491 844 log.go:32] "RunPodSandbox from runtime service failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"5b7fdf5e8076fdd1a1df75f79051b3198c05bbdda431465e5885d8f597bbf525\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory"1740machine # [ 26.881610] k3s[844]: E0920 15:39:34.981597 844 kuberuntime_sandbox.go:71] "Failed to create sandbox for pod" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"5b7fdf5e8076fdd1a1df75f79051b3198c05bbdda431465e5885d8f597bbf525\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/helm-install-niks3-gs2wp"1741machine # [ 26.885675] k3s[844]: E0920 15:39:34.981624 844 kuberuntime_manager.go:1568] "CreatePodSandbox for pod failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"5b7fdf5e8076fdd1a1df75f79051b3198c05bbdda431465e5885d8f597bbf525\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/helm-install-niks3-gs2wp"1742machine # [ 26.891165] k3s[844]: E0920 15:39:34.981730 844 pod_workers.go:1324] "Error syncing pod, skipping" err="failed to \"CreatePodSandbox\" for \"helm-install-niks3-gs2wp_kube-system(bf2a4011-595b-4564-813c-8b8c4a00034b)\" with CreatePodSandboxError: \"Failed to create sandbox for pod \\\"helm-install-niks3-gs2wp_kube-system(bf2a4011-595b-4564-813c-8b8c4a00034b)\\\": rpc error: code = Unknown desc = failed to setup network for sandbox \\\"5b7fdf5e8076fdd1a1df75f79051b3198c05bbdda431465e5885d8f597bbf525\\\": plugin type=\\\"flannel\\\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory\"" pod="kube-system/helm-install-niks3-gs2wp" podUID="bf2a4011-595b-4564-813c-8b8c4a00034b"1743machine # [ 27.138668] k3s[844]: I0920 15:39:35.241738 844 kube.go:163] Node controller sync successful1744machine # [ 27.138825] k3s[844]: I0920 15:39:35.241807 844 vxlan.go:128] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false1745machine # [ 27.143600] systemd[1]: run-netns-cni\x2d1d64fb62\x2d152f\x2da486\x2dcee1\x2dc98b150047ba.mount: Deactivated successfully.1746machine # [ 27.145050] k3s[844]: I0920 15:39:35.248559 844 kube.go:704] List of node(machine) annotations: map[string]string{"alpha.kubernetes.io/provided-node-ip":"10.0.2.15,fec0::d975:31c3:299f:e85", "k3s.io/hostname":"machine", "k3s.io/internal-ip":"10.0.2.15,fec0::d975:31c3:299f:e85", "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"}1747machine # [ 27.150523] k3s[844]: E0920 15:39:35.254024 844 log.go:32] "RunPodSandbox from runtime service failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"1fc4e756d08a9e52f56869d1d01688a2b2c655f57a56b9a90a50a5187f7af0ac\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory"1748machine # [ 27.151882] k3s[844]: E0920 15:39:35.254819 844 kuberuntime_sandbox.go:71] "Failed to create sandbox for pod" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"1fc4e756d08a9e52f56869d1d01688a2b2c655f57a56b9a90a50a5187f7af0ac\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/coredns-c5fdd76cf-r9kxv"1749machine # [ 27.152533] k3s[844]: E0920 15:39:35.254895 844 kuberuntime_manager.go:1568] "CreatePodSandbox for pod failed" err="rpc error: code = Unknown desc = failed to setup network for sandbox \"1fc4e756d08a9e52f56869d1d01688a2b2c655f57a56b9a90a50a5187f7af0ac\": plugin type=\"flannel\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory" pod="kube-system/coredns-c5fdd76cf-r9kxv"1750machine # [ 27.152969] k3s[844]: E0920 15:39:35.255007 844 pod_workers.go:1324] "Error syncing pod, skipping" err="failed to \"CreatePodSandbox\" for \"coredns-c5fdd76cf-r9kxv_kube-system(4e71e95c-229d-424f-98ae-a7acf7ff2a63)\" with CreatePodSandboxError: \"Failed to create sandbox for pod \\\"coredns-c5fdd76cf-r9kxv_kube-system(4e71e95c-229d-424f-98ae-a7acf7ff2a63)\\\": rpc error: code = Unknown desc = failed to setup network for sandbox \\\"1fc4e756d08a9e52f56869d1d01688a2b2c655f57a56b9a90a50a5187f7af0ac\\\": plugin type=\\\"flannel\\\" failed (add): loadFlannelSubnetEnv failed: open /run/flannel/subnet.env: no such file or directory\"" pod="kube-system/coredns-c5fdd76cf-r9kxv" podUID="4e71e95c-229d-424f-98ae-a7acf7ff2a63"1751machine # [ 27.184567] (udev-worker)[1151]: Network interface NamePolicy= disabled on kernel command line.1752machine # [ 27.190666] k3s[844]: I0920 15:39:35.294187 844 iptables.go:50] Starting flannel in iptables mode...1753machine # [ 27.191869] k3s[844]: time="2026-09-20T15:39:35Z" level=warning msg="no subnet found for key: FLANNEL_NETWORK in file: /run/flannel/subnet.env"1754machine # [ 27.194223] k3s[844]: time="2026-09-20T15:39:35Z" level=warning msg="no subnet found for key: FLANNEL_SUBNET in file: /run/flannel/subnet.env"1755machine # [ 27.195790] k3s[844]: I0920 15:39:35.295489 844 kube.go:558] Creating the node lease for IPv4. This is the n.Spec.PodCIDRs: [10.42.0.0/24]1756machine # [ 27.197284] k3s[844]: time="2026-09-20T15:39:35Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_NETWORK in file: /run/flannel/subnet.env"1757machine # [ 27.198821] k3s[844]: time="2026-09-20T15:39:35Z" level=warning msg="no subnet found for key: FLANNEL_IPV6_SUBNET in file: /run/flannel/subnet.env"1758machine # [ 27.203089] k3s[844]: I0920 15:39:35.297169 844 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 rules1759machine # [ 27.216489] dhcpcd[634]: flannel.1: IAID d6:74:a3:b41760machine # [ 27.217358] dhcpcd[634]: flannel.1: adding address fe80::bce4:d6ff:fe74:a3b41761machine # [ 27.246888] k3s[844]: I0920 15:39:35.350494 844 iptables.go:111] Setting up masking rules1762machine # [ 27.260874] k3s[844]: I0920 15:39:35.364444 844 iptables.go:212] Changing default FORWARD chain policy to ACCEPT1763machine # [ 27.274500] k3s[844]: time="2026-09-20T15:39:35Z" level=info msg="Wrote flannel subnet file to /run/flannel/subnet.env"1764machine # [ 27.275821] k3s[844]: time="2026-09-20T15:39:35Z" level=info msg="Running flannel backend"1765machine # [ 27.276855] k3s[844]: I0920 15:39:35.377983 844 vxlan_network.go:68] watching for new subnet leases1766machine # [ 27.277981] k3s[844]: I0920 15:39:35.378010 844 vxlan_network.go:115] starting vxlan device watcher1767machine # [ 27.329979] k3s[844]: I0920 15:39:35.433573 844 iptables.go:358] bootstrap done1768machine # [ 27.354085] k3s[844]: I0920 15:39:35.457630 844 iptables.go:358] bootstrap done1769machine # Error from server (NotFound): namespaces "niks3" not found1770machine # [ 28.229403] dhcpcd[634]: flannel.1: soliciting a DHCP lease1771machine # Error from server (NotFound): namespaces "niks3" not found1772machine # [ 29.017665] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="Started tunnel to 10.0.2.15:6443"1773machine # [ 29.017849] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="Stopped tunnel to 127.0.0.1:6443"1774machine # [ 29.018409] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="Connecting to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1775machine # [ 29.018890] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"1776machine # [ 29.022359] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"1777machine # [ 29.024131] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="Handling backend connection request [machine]"1778machine # [ 29.025171] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="Connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1779machine # [ 29.025582] k3s[844]: time="2026-09-20T15:39:37Z" level=info msg="Remotedialer connected to proxy" url="wss://10.0.2.15:6443/v1-k3s/connect"1780machine # [ 29.350963] dhcpcd[634]: flannel.1: soliciting an IPv6 router1781machine # Error from server (NotFound): namespaces "niks3" not found1782machine # Error from server (NotFound): namespaces "niks3" not found1783machine # Error from server (NotFound): namespaces "niks3" not found1784machine # [ 32.111710] k3s[844]: I0920 15:39:40.214467 844 kuberuntime_manager.go:2095] "Updating runtime config through cri with podcidr" CIDR="10.42.0.0/24"1785machine # [ 32.116104] k3s[844]: I0920 15:39:40.219562 844 kubelet_network.go:47] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="10.42.0.0/24"1786machine # [ 33.085678] k3s[844]: time="2026-09-20T15:39:41Z" level=info msg="Starting network policy controller version v2.6.3-k3s1, built on 1970-01-01T01:01:01Z, go1.26.7"1787machine # [ 33.086179] k3s[844]: I0920 15:39:41.189656 844 network_policy_controller.go:164] Starting network policy controller1788machine # Error from server (NotFound): namespaces "niks3" not found1789machine # [ 33.231368] dhcpcd[634]: flannel.1: probing for an IPv4LL address1790machine # [ 33.242136] k3s[844]: I0920 15:39:41.345338 844 network_policy_controller.go:179] Starting network policy controller full sync goroutine1791machine # Error from server (NotFound): namespaces "niks3" not found1792machine # Error from server (NotFound): namespaces "niks3" not found1793machine # Error from server (NotFound): namespaces "niks3" not found1794machine # Error from server (NotFound): namespaces "niks3" not found1795machine # [ 38.634065] dhcpcd[634]: flannel.1: using IPv4LL address 169.254.156.891796machine # [ 38.636854] dhcpcd[634]: flannel.1: adding route to 169.254.0.0/161797machine # Error from server (NotFound): namespaces "niks3" not found1798machine # [ 38.926312] (udev-worker)[1523]: Network interface NamePolicy= disabled on kernel command line.1799machine # [ 39.086402] cni0: port 1(vethee750b12) entered blocking state1800machine # [ 39.086967] cni0: port 1(vethee750b12) entered disabled state1801machine # [ 39.087776] vethee750b12: entered allmulticast mode1802machine # [ 39.088404] vethee750b12: entered promiscuous mode1803machine # [ 38.941329] (udev-worker)[1562]: Network interface NamePolicy= disabled on kernel command line.1804machine # [ 39.098077] cni0: port 1(vethee750b12) entered blocking state1805machine # [ 39.098708] cni0: port 1(vethee750b12) entered forwarding state1806machine # [ 38.969194] dhcpcd[634]: vethee750b12: IAID 73:11:46:d11807machine # [ 38.970255] dhcpcd[634]: vethee750b12: adding address fe80::306b:73ff:fe11:46d11808machine # [ 39.006567] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount591153442.mount: Deactivated successfully.1809machine # [ 39.069259] systemd[1]: Started libcontainer container 5ee7c0378a2f4a35eaa7114b8f29a162b2a1e00a27c2d31e4fbdb50a52e4d598.1810machine # [ 39.790274] systemd[1]: Started libcontainer container 92dea4a9393da7b0439ae4575d33463b7bf312844fe2d7eb07316112894aac92.1811machine # [ 40.085616] cni0: port 2(vetha2eb1316) entered blocking state1812machine # [ 40.086268] cni0: port 2(vetha2eb1316) entered disabled state1813machine # [ 40.086841] vetha2eb1316: entered allmulticast mode1814machine # [ 40.087668] vetha2eb1316: entered promiscuous mode1815machine # [ 40.104652] cni0: port 2(vetha2eb1316) entered blocking state1816machine # [ 40.105269] cni0: port 2(vetha2eb1316) entered forwarding state1817machine # [ 39.999349] dhcpcd[634]: vetha2eb1316: waiting for carrier1818machine # [ 39.999691] dhcpcd[634]: vetha2eb1316: carrier acquired1819machine # [ 40.008904] dhcpcd[634]: vetha2eb1316: IAID 97:80:a7:3f1820machine # [ 40.009344] dhcpcd[634]: vetha2eb1316: adding address fe80::4c4c:97ff:fe80:a73f1821machine # [ 40.054115] k3s[844]: I0920 15:39:48.156313 844 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/coredns-c5fdd76cf-r9kxv" podStartSLOduration=14.156292904 podStartE2EDuration="14.156292904s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-09-20 15:39:34 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-09-20 15:39:48.123647973 +0000 UTC m=+25.185028263" watchObservedRunningTime="2026-09-20 15:39:48.156292904 +0000 UTC m=+25.217672914"1822machine # Error from server (NotFound): namespaces "niks3" not found1823machine # [ 40.161961] systemd[1]: Started libcontainer container 5dff0528b339e109d27b5d772ec9ca7f6d0fec0beb8b9c2eecc19b3b5f1d6bf0.1824machine # [ 40.405821] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount2352621862.mount: Deactivated successfully.1825machine # [ 40.611224] dhcpcd[634]: vethee750b12: soliciting a DHCP lease1826machine # [ 40.643476] dhcpcd[634]: vetha2eb1316: soliciting a DHCP lease1827machine # [ 41.276769] systemd[1]: var-lib-rancher-k3s-agent-containerd-tmpmounts-containerd\x2dmount301393904.mount: Deactivated successfully.1828machine # [ 41.300929] dhcpcd[634]: vethee750b12: soliciting an IPv6 router1829machine # [ 41.327247] systemd[1]: Started libcontainer container 11be22702f4a67979d2b8b0142821372f4657c3a609abf6f7e5028ac96796408.1830machine # Error from server (NotFound): namespaces "niks3" not found1831machine # [ 41.353656] dhcpcd[634]: flannel.1: no IPv6 Routers available1832machine # [ 42.303955] dhcpcd[634]: vetha2eb1316: soliciting an IPv6 router1833machine # Error from server (NotFound): namespaces "niks3" not found1834machine # [ 42.765417] k3s[844]: I0920 15:39:50.868388 844 alloc.go:329] "allocated clusterIPs" service="niks3/niks3" clusterIPs={"IPv4":"10.43.251.0"}1835machine # [ 42.804952] k3s[844]: I0920 15:39:50.908522 844 controller.go:667] quota admission added evaluator for: cronjobs.batch1836machine # [ 42.854297] systemd[1]: cri-containerd-11be22702f4a67979d2b8b0142821372f4657c3a609abf6f7e5028ac96796408.scope: Deactivated successfully.1837machine # [ 42.856319] systemd[1]: cri-containerd-11be22702f4a67979d2b8b0142821372f4657c3a609abf6f7e5028ac96796408.scope: Consumed 561ms CPU time over 1.526s wall clock time, 35.9M memory peak, 4.1M incoming IP traffic, 81.6K outgoing IP traffic.1838machine # [ 42.892223] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-11be22702f4a67979d2b8b0142821372f4657c3a609abf6f7e5028ac96796408-rootfs.mount: Deactivated successfully.1839machine # [ 42.992085] k3s[844]: I0920 15:39:51.094877 844 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="kube-system/helm-install-niks3-gs2wp" podStartSLOduration=18.094855766 podStartE2EDuration="18.094855766s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-09-20 15:39:33 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-09-20 15:39:50.127098691 +0000 UTC m=+27.188478980" watchObservedRunningTime="2026-09-20 15:39:51.094855766 +0000 UTC m=+28.156235776"1840machine # [ 43.009324] systemd[1]: Created slice libcontainer container kubepods-besteffort-poda50cd9ac_e38b_45a1_b128_6a7ee486d958.slice.1841machine # [ 43.105995] k3s[844]: I0920 15:39:51.209506 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"db\" (UniqueName: \"kubernetes.io/secret/a50cd9ac-e38b-45a1-b128-6a7ee486d958-db\") pod \"niks3-59f7d88555-lgkgc\" (UID: \"a50cd9ac-e38b-45a1-b128-6a7ee486d958\") " pod="niks3/niks3-59f7d88555-lgkgc"1842machine # [ 43.109701] k3s[844]: I0920 15:39:51.209547 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/a50cd9ac-e38b-45a1-b128-6a7ee486d958-token\") pod \"niks3-59f7d88555-lgkgc\" (UID: \"a50cd9ac-e38b-45a1-b128-6a7ee486d958\") " pod="niks3/niks3-59f7d88555-lgkgc"1843machine # [ 43.113198] k3s[844]: I0920 15:39:51.209574 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"s3\" (UniqueName: \"kubernetes.io/secret/a50cd9ac-e38b-45a1-b128-6a7ee486d958-s3\") pod \"niks3-59f7d88555-lgkgc\" (UID: \"a50cd9ac-e38b-45a1-b128-6a7ee486d958\") " pod="niks3/niks3-59f7d88555-lgkgc"1844machine # [ 43.116605] k3s[844]: I0920 15:39:51.209599 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-7cw9z\" (UniqueName: \"kubernetes.io/projected/a50cd9ac-e38b-45a1-b128-6a7ee486d958-kube-api-access-7cw9z\") pod \"niks3-59f7d88555-lgkgc\" (UID: \"a50cd9ac-e38b-45a1-b128-6a7ee486d958\") " pod="niks3/niks3-59f7d88555-lgkgc"1845machine # [ 43.120522] k3s[844]: I0920 15:39:51.209626 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"oidc\" (UniqueName: \"kubernetes.io/configmap/a50cd9ac-e38b-45a1-b128-6a7ee486d958-oidc\") pod \"niks3-59f7d88555-lgkgc\" (UID: \"a50cd9ac-e38b-45a1-b128-6a7ee486d958\") " pod="niks3/niks3-59f7d88555-lgkgc"1846machine # [ 43.518338] cni0: port 3(vethfb981816) entered blocking state1847machine # [ 43.519948] cni0: port 3(vethfb981816) entered disabled state1848machine # [ 43.522361] vethfb981816: entered allmulticast mode1849machine # [ 43.524406] vethfb981816: entered promiscuous mode1850machine # [ 43.537841] cni0: port 3(vethfb981816) entered blocking state1851machine # [ 43.538507] cni0: port 3(vethfb981816) entered forwarding state1852machine # [ 43.436267] (udev-worker)[2054]: Network interface NamePolicy= disabled on kernel command line.1853machine # [ 43.463409] dhcpcd[634]: vethfb981816: IAID fe:9e:cc:371854machine # [ 43.464242] dhcpcd[634]: vethfb981816: adding address fe80::a40d:feff:fe9e:cc371855machine # [ 43.486586] systemd[1]: Started libcontainer container 3bbe92658975530c5bc0f3f7beb731733e96225cc852b3fc13383534b89b46fe.1856machine # [ 43.903602] systemd[1]: Started libcontainer container 9a4c0af0aa71fd67895f1e9fca612d0dacdb59da486c3ddffeebc16e85c42254.1857machine # [ 43.978252] postgres[2155]: [2155] ERROR: relation "goose_db_version" does not exist at character 361858machine # [ 43.979543] postgres[2155]: [2155] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1859machine # [ 44.068480] systemd[1]: cri-containerd-5dff0528b339e109d27b5d772ec9ca7f6d0fec0beb8b9c2eecc19b3b5f1d6bf0.scope: Deactivated successfully.1860machine # [ 44.121044] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-5dff0528b339e109d27b5d772ec9ca7f6d0fec0beb8b9c2eecc19b3b5f1d6bf0-rootfs.mount: Deactivated successfully.1861machine # [ 44.196652] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-5dff0528b339e109d27b5d772ec9ca7f6d0fec0beb8b9c2eecc19b3b5f1d6bf0-shm.mount: Deactivated successfully.1862machine # [ 44.384017] cni0: port 2(vetha2eb1316) entered disabled state1863machine # [ 44.234835] dhcpcd[634]: vetha2eb1316: carrier lost1864machine # [ 44.386326] vetha2eb1316 (unregistering): left allmulticast mode1865machine # [ 44.386915] vetha2eb1316 (unregistering): left promiscuous mode1866machine # [ 44.387946] cni0: port 2(vetha2eb1316) entered disabled state1867machine # [ 44.253401] systemd[1]: run-netns-cni\x2db0303d65\x2d8c1d\x2d498e\x2dafbb\x2d246b4627d09c.mount: Deactivated successfully.1868machine # [ 44.264845] dhcpcd[634]: vetha2eb1316: deleting address fe80::4c4c:97ff:fe80:a73f1869machine # [ 44.286182] k3s[844]: I0920 15:39:52.389355 844 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/niks3-59f7d88555-lgkgc" podStartSLOduration=1.38933146 podStartE2EDuration="1.38933146s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-09-20 15:39:51 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-09-20 15:39:52.17643429 +0000 UTC m=+29.237814301" watchObservedRunningTime="2026-09-20 15:39:52.38933146 +0000 UTC m=+29.450711470"1870machine # [ 44.304257] dhcpcd[634]: vetha2eb1316: removing interface1871machine # [ 44.416149] k3s[844]: I0920 15:39:52.519705 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-config\") pod \"bf2a4011-595b-4564-813c-8b8c4a00034b\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") "1872machine # [ 44.422798] k3s[844]: I0920 15:39:52.519747 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-tmp\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-tmp\") pod \"bf2a4011-595b-4564-813c-8b8c4a00034b\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") "1873machine # [ 44.428498] k3s[844]: I0920 15:39:52.519776 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-kube-api-access-sgc5d\" (UniqueName: \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-kube-api-access-sgc5d\") pod \"bf2a4011-595b-4564-813c-8b8c4a00034b\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") "1874machine # [ 44.433287] k3s[844]: I0920 15:39:52.519805 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-helm\") pod \"bf2a4011-595b-4564-813c-8b8c4a00034b\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") "1875machine # [ 44.437405] k3s[844]: I0920 15:39:52.519836 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/configmap/bf2a4011-595b-4564-813c-8b8c4a00034b-content\" (UniqueName: \"kubernetes.io/configmap/bf2a4011-595b-4564-813c-8b8c4a00034b-content\") pod \"bf2a4011-595b-4564-813c-8b8c4a00034b\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") "1876machine # [ 44.441173] k3s[844]: I0920 15:39:52.519862 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-values\" (UniqueName: \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-values\") pod \"bf2a4011-595b-4564-813c-8b8c4a00034b\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") "1877machine # [ 44.444912] k3s[844]: I0920 15:39:52.519888 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-cache\") pod \"bf2a4011-595b-4564-813c-8b8c4a00034b\" (UID: \"bf2a4011-595b-4564-813c-8b8c4a00034b\") "1878machine # [ 44.449350] k3s[844]: I0920 15:39:52.526072 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/configmap/bf2a4011-595b-4564-813c-8b8c4a00034b-content" pod "bf2a4011-595b-4564-813c-8b8c4a00034b" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b"). InnerVolumeSpecName "content". PluginName "kubernetes.io/configmap", VolumeGIDValue ""1879machine # [ 44.453417] k3s[844]: I0920 15:39:52.530999 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-config" pod "bf2a4011-595b-4564-813c-8b8c4a00034b" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b"). InnerVolumeSpecName "klipper-config". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1880machine # [ 44.454108] k3s[844]: I0920 15:39:52.531333 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-cache" pod "bf2a4011-595b-4564-813c-8b8c4a00034b" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b"). InnerVolumeSpecName "klipper-cache". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1881machine # [ 44.454566] k3s[844]: I0920 15:39:52.532874 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-tmp" pod "bf2a4011-595b-4564-813c-8b8c4a00034b" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b"). InnerVolumeSpecName "tmp". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1882machine # [ 44.455147] systemd[1]: var-lib-kubelet-pods-bf2a4011\x2d595b\x2d4564\x2d813c\x2d8b8c4a00034b-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dcache.mount: Deactivated successfully.1883machine # [ 44.455717] k3s[844]: I0920 15:39:52.537191 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-values" pod "bf2a4011-595b-4564-813c-8b8c4a00034b" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b"). InnerVolumeSpecName "values". PluginName "kubernetes.io/projected", VolumeGIDValue ""1884machine # [ 44.456100] k3s[844]: I0920 15:39:52.540888 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-helm" pod "bf2a4011-595b-4564-813c-8b8c4a00034b" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b"). InnerVolumeSpecName "klipper-helm". PluginName "kubernetes.io/empty-dir", VolumeGIDValue ""1885machine # [ 44.456696] k3s[844]: I0920 15:39:52.552433 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-kube-api-access-sgc5d" pod "bf2a4011-595b-4564-813c-8b8c4a00034b" (UID: "bf2a4011-595b-4564-813c-8b8c4a00034b"). InnerVolumeSpecName "kube-api-access-sgc5d". PluginName "kubernetes.io/projected", VolumeGIDValue ""1886machine # [ 44.517332] k3s[844]: I0920 15:39:52.620893 844 reconciler_common.go:299] "Volume detached for volume \"values\" (UniqueName: \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-values\") on node \"machine\" DevicePath \"\""1887machine # [ 44.517519] k3s[844]: I0920 15:39:52.620932 844 reconciler_common.go:299] "Volume detached for volume \"klipper-cache\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-cache\") on node \"machine\" DevicePath \"\""1888machine # [ 44.517924] k3s[844]: I0920 15:39:52.620951 844 reconciler_common.go:299] "Volume detached for volume \"klipper-config\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-config\") on node \"machine\" DevicePath \"\""1889machine # [ 44.518702] k3s[844]: I0920 15:39:52.620965 844 reconciler_common.go:299] "Volume detached for volume \"tmp\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-tmp\") on node \"machine\" DevicePath \"\""1890machine # [ 44.519243] k3s[844]: I0920 15:39:52.620978 844 reconciler_common.go:299] "Volume detached for volume \"kube-api-access-sgc5d\" (UniqueName: \"kubernetes.io/projected/bf2a4011-595b-4564-813c-8b8c4a00034b-kube-api-access-sgc5d\") on node \"machine\" DevicePath \"\""1891machine # [ 44.519659] k3s[844]: I0920 15:39:52.620990 844 reconciler_common.go:299] "Volume detached for volume \"klipper-helm\" (UniqueName: \"kubernetes.io/empty-dir/bf2a4011-595b-4564-813c-8b8c4a00034b-klipper-helm\") on node \"machine\" DevicePath \"\""1892machine # [ 44.520109] k3s[844]: I0920 15:39:52.621002 844 reconciler_common.go:299] "Volume detached for volume \"content\" (UniqueName: \"kubernetes.io/configmap/bf2a4011-595b-4564-813c-8b8c4a00034b-content\") on node \"machine\" DevicePath \"\""1893machine # [ 44.703976] dhcpcd[634]: vethfb981816: soliciting an IPv6 router1894machine # [ 44.892730] systemd[1]: var-lib-kubelet-pods-bf2a4011\x2d595b\x2d4564\x2d813c\x2d8b8c4a00034b-volumes-kubernetes.io\x7eprojected-kube\x2dapi\x2daccess\x2dsgc5d.mount: Deactivated successfully.1895machine # [ 44.893604] systemd[1]: var-lib-kubelet-pods-bf2a4011\x2d595b\x2d4564\x2d813c\x2d8b8c4a00034b-volumes-kubernetes.io\x7eprojected-values.mount: Deactivated successfully.1896machine # [ 44.894870] systemd[1]: var-lib-kubelet-pods-bf2a4011\x2d595b\x2d4564\x2d813c\x2d8b8c4a00034b-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dhelm.mount: Deactivated successfully.1897machine # [ 44.895993] systemd[1]: var-lib-kubelet-pods-bf2a4011\x2d595b\x2d4564\x2d813c\x2d8b8c4a00034b-volumes-kubernetes.io\x7eempty\x2ddir-tmp.mount: Deactivated successfully.1898machine # [ 44.897217] systemd[1]: var-lib-kubelet-pods-bf2a4011\x2d595b\x2d4564\x2d813c\x2d8b8c4a00034b-volumes-kubernetes.io\x7eempty\x2ddir-klipper\x2dconfig.mount: Deactivated successfully.1899machine # [ 45.053396] k3s[844]: I0920 15:39:53.156803 844 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="5dff0528b339e109d27b5d772ec9ca7f6d0fec0beb8b9c2eecc19b3b5f1d6bf0"1900machine # [ 45.061383] systemd[1]: Removed slice libcontainer container kubepods-burstable-podbf2a4011_595b_4564_813c_8b8c4a00034b.slice.1901machine # [ 45.062110] systemd[1]: kubepods-burstable-podbf2a4011_595b_4564_813c_8b8c4a00034b.slice: Consumed 591ms CPU time over 19.476s wall clock time, 36.1M memory peak, 4.1M incoming IP traffic, 81.6K outgoing IP traffic.1902machine # [ 45.369066] dhcpcd[634]: vethfb981816: soliciting a DHCP lease1903machine # [ 45.611876] dhcpcd[634]: vethee750b12: probing for an IPv4LL address1904machine: (finished: waiting for success: kubectl -n niks3 rollout status deployment niks3 --timeout=10s, in 27.96 seconds)1905machine: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true1906machine: (finished: must succeed: kubectl -n niks3 get deployment niks3 -o jsonpath='{.metadata.annotations.reloader\.stakater\.com/auto}' | grep true, in 0.11 seconds)1907machine: waiting for success: curl -sf http://localhost:30051/readyz | grep OK1908machine: (finished: waiting for success: curl -sf http://localhost:30051/readyz | grep OK, in 0.03 seconds)1909(finished: subtest: chart deploys and becomes ready, in 28.11 seconds)1910machine: waiting for success: kubectl -n ci get sa builder1911machine: (finished: waiting for success: kubectl -n ci get sa builder, in 0.11 seconds)1912machine: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt1913machine: (finished: must succeed: kubectl -n ci create token builder --audience niks3 > /tmp/builder.jwt, in 0.11 seconds)1914machine: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt1915machine: (finished: must succeed: kubectl -n ci create token intruder --audience niks3 > /tmp/intruder.jwt, in 0.11 seconds)1916machine: must succeed: readlink -f /run/current-system/sw/bin/niks31917machine: (finished: must succeed: readlink -f /run/current-system/sw/bin/niks3, in 0.01 seconds)1918subtest: allowed service account can push via workload identity1919machine: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/52ijsbffw6z8rz7wp3g0y2yhw3nglhap-niks3-1.12.0-beta.2 2>&11920machine # [ 50.136367] dhcpcd[634]: vethee750b12: using IPv4LL address 169.254.38.2201921machine # [ 50.138268] dhcpcd[634]: vethee750b12: adding route to 169.254.0.0/161922machine # [ 50.369844] dhcpcd[634]: vethfb981816: probing for an IPv4LL address1923machine: (finished: must succeed: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/builder.jwt niks3 push /nix/store/52ijsbffw6z8rz7wp3g0y2yhw3nglhap-niks3-1.12.0-beta.2 2>&1, in 0.95 seconds)1924machine: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/52ijsbffw6z8rz7wp3g0y2yhw3nglhap.narinfo1925machine: (finished: must succeed: curl -sf -H 'Authorization: Bearer test-token-that-is-at-least-36-characters-long' -I http://localhost:30051/api/objects/52ijsbffw6z8rz7wp3g0y2yhw3nglhap.narinfo, in 0.02 seconds)1926(finished: subtest: allowed service account can push via workload identity, in 0.98 seconds)1927subtest: write scope does not grant admin1928machine: must succeed: curl -s -o /dev/null -w '%{http_code}' -H "Authorization: Bearer $(cat /tmp/builder.jwt)" http://localhost:30051/api/gc/status1929machine: (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)1930(finished: subtest: write scope does not grant admin, in 0.03 seconds)1931subtest: other service accounts are rejected1932machine: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/52ijsbffw6z8rz7wp3g0y2yhw3nglhap-niks3-1.12.0-beta.2 2>&11933machine: (finished: must fail: NIKS3_SERVER_URL=http://localhost:30051 NIKS3_AUTH_TOKEN_FILE=/tmp/intruder.jwt niks3 push /nix/store/52ijsbffw6z8rz7wp3g0y2yhw3nglhap-niks3-1.12.0-beta.2 2>&1, in 0.11 seconds)1934(finished: subtest: other service accounts are rejected, in 0.11 seconds)1935subtest: gc cronjob runs against the service1936machine: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual1937machine: (finished: must succeed: kubectl -n niks3 create job --from=cronjob/niks3-gc gc-manual, in 0.15 seconds)1938machine: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s1939machine # [ 50.898133] systemd[1]: Created slice libcontainer container kubepods-besteffort-pod8468c430_d263_44f0_b527_bb86623cfb4c.slice.1940machine # [ 51.064978] k3s[844]: I0920 15:39:59.168213 844 reconciler_common.go:251] "operationExecutor.VerifyControllerAttachedVolume started for volume \"token\" (UniqueName: \"kubernetes.io/secret/8468c430-d263-44f0-b527-bb86623cfb4c-token\") pod \"gc-manual-sxrbn\" (UID: \"8468c430-d263-44f0-b527-bb86623cfb4c\") " pod="niks3/gc-manual-sxrbn"1941machine # [ 51.426002] cni0: port 2(veth0250db42) entered blocking state1942machine # [ 51.427362] cni0: port 2(veth0250db42) entered disabled state1943machine # [ 51.428980] veth0250db42: entered allmulticast mode1944machine # [ 51.431371] veth0250db42: entered promiscuous mode1945machine # [ 51.444716] cni0: port 2(veth0250db42) entered blocking state1946machine # [ 51.445320] cni0: port 2(veth0250db42) entered forwarding state1947machine # [ 51.325132] (udev-worker)[2547]: Network interface NamePolicy= disabled on kernel command line.1948machine # [ 51.351945] dhcpcd[634]: veth0250db42: IAID 1d:3b:9f:081949machine # [ 51.352591] dhcpcd[634]: veth0250db42: adding address fe80::c9a:1dff:fe3b:9f081950machine # [ 51.386244] systemd[1]: Started libcontainer container b1eca2612f122a58ad02c9245c287730aefeb8ac589d5e02fd96821b9957b0e9.1951machine # [ 51.486729] systemd[1]: Started libcontainer container 5a0f88a5a5cedb0c1fd486acdd55935f36d9b40226886e2e9c172aad3d79880b.1952machine # [ 52.103715] k3s[844]: I0920 15:40:00.206414 844 pod_startup_latency_tracker.go:148] "Observed pod startup duration" pod="niks3/gc-manual-sxrbn" podStartSLOduration=2.206384185 podStartE2EDuration="2.206384185s" totalImagesPullingTime="0s" totalInitContainerRuntime="0s" isStatefulPod=false podCreationTimestamp="2026-09-20 15:39:58 +0000 UTC" imagePullSessionsCount=0 imagePullSessionsStartsCount=0 observedRunningTime="2026-09-20 15:40:00.206057608 +0000 UTC m=+37.267440691" watchObservedRunningTime="2026-09-20 15:40:00.206384185 +0000 UTC m=+37.267767268"1953machine # [ 53.214935] dhcpcd[634]: veth0250db42: soliciting an IPv6 router1954machine # [ 53.222897] dhcpcd[634]: veth0250db42: soliciting a DHCP lease1955machine # [ 53.303656] dhcpcd[634]: vethee750b12: no IPv6 Routers available1956machine # [ 53.551407] systemd[1]: cri-containerd-5a0f88a5a5cedb0c1fd486acdd55935f36d9b40226886e2e9c172aad3d79880b.scope: Deactivated successfully.1957machine # [ 53.556536] systemd[1]: cri-containerd-5a0f88a5a5cedb0c1fd486acdd55935f36d9b40226886e2e9c172aad3d79880b.scope: Consumed 37ms CPU time over 2.064s wall clock time, 4.3M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1958machine # [ 53.592271] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-5a0f88a5a5cedb0c1fd486acdd55935f36d9b40226886e2e9c172aad3d79880b-rootfs.mount: Deactivated successfully.1959machine # [ 55.109126] systemd[1]: cri-containerd-b1eca2612f122a58ad02c9245c287730aefeb8ac589d5e02fd96821b9957b0e9.scope: Deactivated successfully.1960machine # [ 55.140765] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-b1eca2612f122a58ad02c9245c287730aefeb8ac589d5e02fd96821b9957b0e9-rootfs.mount: Deactivated successfully.1961machine # [ 55.170709] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-b1eca2612f122a58ad02c9245c287730aefeb8ac589d5e02fd96821b9957b0e9-shm.mount: Deactivated successfully.1962machine # [ 55.351659] cni0: port 2(veth0250db42) entered disabled state1963machine # [ 55.202864] dhcpcd[634]: veth0250db42: carrier lost1964machine # [ 55.354425] veth0250db42 (unregistering): left allmulticast mode1965machine # [ 55.354999] veth0250db42 (unregistering): left promiscuous mode1966machine # [ 55.355936] cni0: port 2(veth0250db42) entered disabled state1967machine # [ 55.226622] systemd[1]: run-netns-cni\x2de21740ef\x2d6e2b\x2d4466\x2d86b1\x2d903b64a9172b.mount: Deactivated successfully.1968machine # [ 55.242232] dhcpcd[634]: veth0250db42: deleting address fe80::c9a:1dff:fe3b:9f081969machine # [ 55.281245] dhcpcd[634]: veth0250db42: removing interface1970machine # [ 55.390152] k3s[844]: I0920 15:40:03.493266 844 reconciler_common.go:163] "operationExecutor.UnmountVolume started for volume \"kubernetes.io/secret/8468c430-d263-44f0-b527-bb86623cfb4c-token\" (UniqueName: \"kubernetes.io/secret/8468c430-d263-44f0-b527-bb86623cfb4c-token\") pod \"8468c430-d263-44f0-b527-bb86623cfb4c\" (UID: \"8468c430-d263-44f0-b527-bb86623cfb4c\") "1971machine # [ 55.397281] systemd[1]: var-lib-kubelet-pods-8468c430\x2dd263\x2d44f0\x2db527\x2dbb86623cfb4c-volumes-kubernetes.io\x7esecret-token.mount: Deactivated successfully.1972machine # [ 55.399644] k3s[844]: I0920 15:40:03.503238 844 operation_generator.go:780] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/8468c430-d263-44f0-b527-bb86623cfb4c-token" pod "8468c430-d263-44f0-b527-bb86623cfb4c" (UID: "8468c430-d263-44f0-b527-bb86623cfb4c"). InnerVolumeSpecName "token". PluginName "kubernetes.io/secret", VolumeGIDValue ""1973machine # [ 55.490061] k3s[844]: I0920 15:40:03.593499 844 reconciler_common.go:299] "Volume detached for volume \"token\" (UniqueName: \"kubernetes.io/secret/8468c430-d263-44f0-b527-bb86623cfb4c-token\") on node \"machine\" DevicePath \"\""1974machine # [ 55.570369] dhcpcd[634]: vethfb981816: using IPv4LL address 169.254.84.2041975machine # [ 55.572889] dhcpcd[634]: vethfb981816: adding route to 169.254.0.0/161976machine # [ 55.909185] systemd[1]: Removed slice libcontainer container kubepods-besteffort-pod8468c430_d263_44f0_b527_bb86623cfb4c.slice.1977machine # [ 55.910752] systemd[1]: kubepods-besteffort-pod8468c430_d263_44f0_b527_bb86623cfb4c.slice: Consumed 66ms CPU time over 5.010s wall clock time, 4.8M memory peak, 1.5K incoming IP traffic, 987B outgoing IP traffic.1978machine # [ 56.099376] k3s[844]: I0920 15:40:04.202515 844 pod_container_deletor.go:80] "Container not found in pod's containers" containerID="b1eca2612f122a58ad02c9245c287730aefeb8ac589d5e02fd96821b9957b0e9"1979machine: (finished: waiting for success: kubectl -n niks3 wait --for=condition=complete job/gc-manual --timeout=10s, in 5.44 seconds)1980(finished: subtest: gc cronjob runs against the service, in 5.59 seconds)1981subtest: helm test hook passes1982machine: must succeed: helm test -n niks3 niks3 --timeout 2m >&21983machine # [ 56.708281] dhcpcd[634]: vethfb981816: no IPv6 Routers available1984machine # [ 57.158911] dhcpcd[634]: segfault at 58743cd68 ip 00005873febc9cb3 sp 00007ffc168474a8 error 4 in dhcpcd[38cb3,5873feb9a000+40000] likely on CPU 0 (core 0, socket 0)1985machine # [ 57.162545] Code: 45 ae 01 e9 0f fe ff ff 0f 1f 80 00 00 00 00 c6 45 af 01 e9 ff fd ff ff e8 fa 05 fd ff 66 2e 0f 1f 84 00 00 00 00 00 48 8b 07 <48> 8b 80 50 03 00 00 48 85 c0 74 31 90 48 8b 00 48 85 c0 74 1e 481986machine # [ 57.025535] systemd-coredump[2803]: Process 634 (dhcpcd) of user 999 terminated abnormally with signal 11/SEGV, processing...1987machine # [ 57.035387] systemd[1]: Created slice Slice /system/systemd-coredump.1988machine # [ 57.038775] systemd[1]: Started Process Core Dump (PID 2803/UID 0).1989machine # [ 57.136224] systemd-coredump[2804]: Process 634 (dhcpcd) of user 999 dumped core.1990machine # 1991machine # Module udev.so without build-id.1992machine # Module dhcpcd without build-id.1993machine # Stack trace of thread 634:1994machine # #0 0x00005873febc9cb3 ipv6nd_expire (dhcpcd + 0x38cb3)1995machine # #1 0x00005873feba306a eloop_start (dhcpcd + 0x1206a)1996machine # #2 0x00005873feb9b300 main (dhcpcd + 0xa300)1997machine # #3 0x000078da76cb4285 __libc_start_call_main (libc.so.6 + 0x2b285)1998machine # #4 0x000078da76cb4338 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x2b338)1999machine # #5 0x00005873feb9c365 _start (dhcpcd + 0xb365)2000machine # ELF object binary architecture: AMD x86-642001machine # 2002machine # [ 57.149846] systemd[1]: systemd-coredump@0-1-2803_2804-0.service: Deactivated successfully.2003machine # [ 57.170654] systemd[1]: dhcpcd.service: Main process exited, code=dumped, status=11/SEGV2004machine # [ 57.172055] systemd[1]: dhcpcd.service: Failed with result 'core-dump'.2005machine # [ 57.174869] systemd[1]: dhcpcd.service: Consumed 383ms CPU time over 50.735s wall clock time, 6.1M memory peak, 8K written to disk, 96B incoming IP traffic, 840B outgoing IP traffic.2006machine # [ 57.214934] systemd[1]: Created slice libcontainer container kubepods-besteffort-podb570ab48_8499_4d64_a78d_28b2ac40b4ee.slice.2007machine # [ 57.398830] cni0: port 2(veth1bc2a0bf) entered blocking state2008machine # [ 57.399621] cni0: port 2(veth1bc2a0bf) entered disabled state2009machine # [ 57.400433] veth1bc2a0bf: entered allmulticast mode2010machine # [ 57.400968] veth1bc2a0bf: entered promiscuous mode2011machine # [ 57.253493] (udev-worker)[2758]: Network interface NamePolicy= disabled on kernel command line.2012machine # [ 57.414813] cni0: port 2(veth1bc2a0bf) entered blocking state2013machine # [ 57.415431] cni0: port 2(veth1bc2a0bf) entered forwarding state2014machine # [ 57.312338] systemd[1]: dhcpcd.service: Scheduled restart job, restart counter is at 1.2015machine # [ 57.315919] systemd[1]: Starting DHCP Client...2016machine # [ 57.366988] systemd[1]: Started libcontainer container d6489a1d58ecb5a05868741eda16393e305e590806e9a43b6c5b35c24aaea9c1.2017machine # [ 57.439345] dhcpcd[2902]: dhcpcd-10.3.2 starting2018machine # [ 57.441608] dhcpcd[2936]: dev: loaded udev2019machine # [ 57.442870] dhcpcd[2936]: DUID 00:01:00:01:32:42:ba:a2:52:54:00:12:34:562020machine # [ 57.501753] dhcpcd[2936]: eth0: IAID 00:12:34:562021machine # [ 57.502710] dhcpcd[2936]: flannel.1: IAID d6:74:a3:b42022machine # [ 57.503607] dhcpcd[2936]: vethee750b12: IAID 73:11:46:d12023machine # [ 57.504398] dhcpcd[2936]: vethfb981816: IAID fe:9e:cc:372024machine # [ 57.505397] dhcpcd[2936]: veth1bc2a0bf: IAID 8d:84:f5:062025machine # [ 57.506136] dhcpcd[2936]: vethee750b12: soliciting an IPv6 router2026machine # [ 57.510244] systemd[1]: Started libcontainer container 0d94452c07b15368c173b1637302820580ad64f4fe552fba79a0e07ed6909963.2027machine # [ 57.563341] systemd[1]: cri-containerd-0d94452c07b15368c173b1637302820580ad64f4fe552fba79a0e07ed6909963.scope: Deactivated successfully.2028machine # [ 57.567168] systemd[1]: cri-containerd-0d94452c07b15368c173b1637302820580ad64f4fe552fba79a0e07ed6909963.scope: Consumed 29ms CPU time over 52ms wall clock time, 4.6M memory peak, 693B incoming IP traffic, 495B outgoing IP traffic.2029machine # [ 57.663951] dhcpcd[2936]: flannel.1: soliciting a DHCP lease2030machine # [ 57.690551] dhcpcd[2936]: veth1bc2a0bf: soliciting a DHCP lease2031machine # [ 57.968839] dhcpcd[2936]: flannel.1: soliciting an IPv6 router2032machine # [ 58.235224] dhcpcd[2936]: vethfb981816: soliciting an IPv6 router2033machine # [ 58.383651] dhcpcd[2936]: eth0: soliciting an IPv6 router2034machine # [ 58.385591] dhcpcd[2936]: eth0: Router Advertisement from fe80::22035machine # [ 58.387782] dhcpcd[2936]: eth0: adding address fec0::5054:ff:fe12:3456/642036machine # [ 58.430253] dhcpcd[2936]: vethfb981816: soliciting a DHCP lease2037machine # [ 58.877962] dhcpcd[2936]: vethee750b12: soliciting a DHCP lease2038machine # [ 59.136441] systemd[1]: cri-containerd-d6489a1d58ecb5a05868741eda16393e305e590806e9a43b6c5b35c24aaea9c1.scope: Deactivated successfully.2039machine # [ 59.187430] systemd[1]: run-k3s-containerd-io.containerd.runtime.v2.task-k8s.io-d6489a1d58ecb5a05868741eda16393e305e590806e9a43b6c5b35c24aaea9c1-rootfs.mount: Deactivated successfully.2040machine # [ 59.214183] systemd[1]: run-k3s-containerd-io.containerd.grpc.v1.cri-sandboxes-d6489a1d58ecb5a05868741eda16393e305e590806e9a43b6c5b35c24aaea9c1-shm.mount: Deactivated successfully.2041machine # [ 59.394409] cni0: port 2(veth1bc2a0bf) entered disabled state2042machine # [ 59.244587] dhcpcd[2936]: veth1bc2a0bf: carrier lost2043machine # [ 59.396611] veth1bc2a0bf (unregistering): left allmulticast mode2044machine # [ 59.397777] veth1bc2a0bf (unregistering): left promiscuous mode2045machine # [ 59.398900] cni0: port 2(veth1bc2a0bf) entered disabled state2046machine # [ 59.272597] systemd[1]: run-netns-cni\x2df05eb132\x2d127b\x2d195a\x2d3970\x2d1d316ea860f0.mount: Deactivated successfully.2047machine # NAME: niks32048machine # LAST DEPLOYED: Sun Sep 20 15:39:50 20262049machine # NAMESPACE: niks32050machine # STATUS: deployed2051machine # REVISION: 12052machine # DESCRIPTION: Install complete2053machine # TEST SUITE: niks3-test2054machine # Last Started: Sun Sep 20 15:40:05 20262055machine # Last Completed: Sun Sep 20 15:40:07 20262056machine # Phase: Succeeded2057machine: (finished: must succeed: helm test -n niks3 niks3 --timeout 2m >&2, in 3.02 seconds)2058(finished: subtest: helm test hook passes, in 3.02 seconds)2059machine # [ 59.331296] dhcpcd[2936]: veth1bc2a0bf: removing interface2060(finished: run the VM test script, in 60.23 seconds)2061test script finished in 60.26s2062cleanup2063kill QemuMachine (pid 45)2064machine # qemu-system-x86_64: terminating on signal 15 from pid 39 (/nix/store/d64q19q1xjdwfhqx6czvrjgrhq0n3lcc-python3-3.14.7/bin/python3.14)2065machine # [2026-09-20T15:40:07Z INFO virtiofsd] Client disconnected, shutting down2066machine # [2026-09-20T15:40:07Z INFO virtiofsd] Client disconnected, shutting down2067machine # [2026-09-20T15:40:07Z INFO virtiofsd] Client disconnected, shutting down2068(finished: cleanup, in 0.65 seconds)2069additionally exposed symbols:2070 machine,2071 vlan1,2072 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_ssh2073time=2026-09-20T15:39:57.856Z level=INFO msg="Uploading 8 paths to localhost (0 already cached)"2074time=2026-09-20T15:39:57.856Z level=INFO msg="Uploading fh8svr4ds87z84iarfnxrlfpjlbmc816-tzdata-2026c (2.0MB)"2075time=2026-09-20T15:39:57.856Z level=INFO msg="Uploading lm3pknxi0ipypy3lxh1wmm8wvvavdwrn-glibc-2.42-84 (33.4MB)"2076time=2026-09-20T15:39:57.856Z level=INFO msg="Uploading m07syxhld8hpprrdmzq565ziia6vlw9l-xgcc-15.3.0-libgcc (193.0KB)"2077time=2026-09-20T15:39:57.856Z level=INFO msg="Uploading 9v00p4m9cdzn23gmy5m9d3a6c3gfwhl7-iana-etc-20251215 (557.8KB)"2078time=2026-09-20T15:39:57.857Z level=INFO msg="Uploading i3jw341xs88r6wxf1j22rjx1mmd8cfjw-libidn2-2.3.8 (359.5KB)"2079time=2026-09-20T15:39:57.858Z level=INFO msg="Uploading 52ijsbffw6z8rz7wp3g0y2yhw3nglhap-niks3-1.12.0-beta.2 (7.7MB)"2080time=2026-09-20T15:39:57.859Z level=INFO msg="Uploading bv3lx708clpz3m6zbd5742np4dlry0yj-libunistring-1.4.2 (2.0MB)"2081time=2026-09-20T15:39:57.862Z level=INFO msg="Uploading 549nkjs10xhma2f9kx3rxw61kym0abjx-mailcap-2.1.54 (116.6KB)"2082time=2026-09-20T15:39:58.630Z level=INFO msg="Uploading 8 narinfos"2083time=2026-09-20T15:39:58.661Z level=INFO msg="Upload complete. (878ms)"2084