VMExtensionProvisioningError with capi-ubun2-2204 and capi-ubun2-2404

[thiDucTran]

/kind bug

What steps did you take and what happened:

1. clusterctl generate cluster capz-private --infrastructure azure --kubernetes-version v1.31.4 --control-plane-machine-count=1 --worker-machine-count=1
2. Then I add on the below to the generated yaml file

      image:
        computeGallery:
          gallery: "ClusterAPI-f72ceb4f-5159-4c26-a0fe-2ea738f0d019"
          name: "capi-ubun2-2404"
          version: "1.31.4"

networkSpec:
    privateDNSZoneName: "capz-private.capz.io"
    apiServerLB:
      type: Internal
      frontendIPs:
      - name: lb-private-ip-frontend
        privateIP: 172.19.2.100
    controlPlaneOutboundLB:
      frontendIPsCount: 1
    nodeOutboundLB:
      frontendIPsCount: 1
    subnets:
    - name: control-plane-subnet
      role: control-plane
      cidrBlocks:
      - 172.19.2.0/25
    - name: node-subnet
      role: node
      cidrBlocks:
        - 172.19.2.128/25
    vnet:
      name: vnet-capz-private
      cidrBlocks:
      - 172.19.2.0/24
      peerings:
      - resourceGroup: rg-name
        remoteVnetName: vnet-capi-mgmt-stage

3. The cluster is Provisioned but: I see 2 errors (below), KubeAdmControlPlane not initialized

E0116 16:26:38.836076       1 cluster_accessor.go:257] "Connect failed" err="error creating HTTP client and mapper: cluster is not reachable: Get \"https://apiserver.capz-private.capz.io:6443/?timeout=5s\": context deadline exceeded" controller="clustercache" controllerGroup="cluster.x-k8s.io" controllerKind="Cluster" Cluster="default/capz-private" namespace="default" name="capz-private" reconcileID="4ec298dc-f392-4809-9426-d35cf8bfa55d"         

E0116 16:31:31.645375       1 controller.go:324] "Reconciler error" err=<failed to reconcile AzureMachine: failed to reconcile AzureMachine service vmextensions: extension state failed. This likely means the Kubernetes node bootstrapping process failed or timed out. Check VM boot diagnostics logs to learn more: failed to create or update resource thi-poc-capz-private/CAPZ.Linux.Bootstrapping (service: vmextensions): GET https://management.azure.com/subscriptions/9d54088e-89a6-4a3a-8f91-05699ba3c93a/providers/Microsoft.Compute/locations/northcentralus/operations 6921441d-f760-44e3-8db1-b7aa18c05a5e --------------------------------------------------------------------------------                                                            RESPONSE 200: 200 OK
ERROR CODE: VMExtensionProvisioningError  --------------------------------------------------------------------------------                                                                                                                                                                                                 "code": "VMExtensionProvisioningError",
"message": "VM has reported a failure when processing extension 'CAPZ.Linux.Bootstrapping' (publisher 'Microsoft.Azure.ContainerUpstream' and type 'CAPZ.Linux.Bootstrapping'). Error message: 'Enable failed: failed to execute command: command terminated with exit status=1\n[stdout]\n\n[stderr]\n'. More information on troubleshooting is available at https://aka.ms/vmextensionlinuxtroubleshoot.

What did you expect to happen:

1. KubeAdmControlPlane gets initialized, CAPZ.Linux.Bootstrapping executes successfully

Anything else you would like to add:

• The logs mentioned in https://learn.microsoft.com/en-us/azure/virtual-machines/extensions/features-linux?tabs=azure-cli#troubleshoot-vm-extensions does not give any additional info..at least to me it doesnt..i can share it if requested
• VNET, Subnets, and Network security groups do not pre-exist..CAPI creates them
• Even though the bootstrapping does not execute successfully, I can do clusterctl get kubeconfig and do kubectl get po to prove that the API server is functioning and there is not network connectivity issue
• Compared to the cluster that I don't specify the API SERVER LB as type: Internal, I noticed that kube-proxy is missing..may be that is related to the boostrapping
• Using the same node image, I can create and have a functioning cluster if I don't specify the API SERVER LB as type: Internal

Environment:

• cluster-api-provider-azure version
  
• Kubernetes version: (use kubectl version): v1.30.6
• OS (e.g. from /etc/os-release): 20.04.6 LTS (Focal Fossa)
• clusterctl: v1.9.3

[thiDucTran]

I found https://kubernetes.slack.com/archives/CEX9HENG7/p1694713968423129 ..but my issue is not exactly the same. as in ..

• /var/log/cloud-init.log : empty
• /var/log/cloud-init-output.log: just key pair logs
• systemctl status kubelet : it's running

● kubelet.service - kubelet: The Kubernetes Node Agent
     Loaded: loaded (/usr/lib/systemd/system/kubelet.service; enabled; preset: enabled)
    Drop-In: /usr/lib/systemd/system/kubelet.service.d
             └─10-kubeadm.conf
     Active: active (running) since Thu 2025-01-16 18:53:26 UTC; 14min ago
       Docs: https://kubernetes.io/docs/
   Main PID: 2009 (kubelet)
      Tasks: 16 (limit: 38504)
     Memory: 49.2M (peak: 53.2M)
        CPU: 18.720s
     CGroup: /system.slice/kubelet.service
             └─2009 /usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.yaml --cloud-provider=external --container-runtime-endpoint=unix:///var/run/containerd/containerd.sock --pod-infra-container-image=registry.k8s.io/pause:3.10 --pod-infra-container-image=registry.k8s.io/pause:3.9

• journalctl -xeu kubelet

Jan 16 18:53:11 capz-private-control-plane-zwk22 systemd[1]: Started kubelet.service - kubelet: The Kubernetes Node Agent.
░░ Subject: A start job for unit kubelet.service has finished successfully
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ A start job for unit kubelet.service has finished successfully.
░░
░░ The job identifier is 198.
Jan 16 18:53:11 capz-private-control-plane-zwk22 (kubelet)[1176]: kubelet.service: Referenced but unset environment variable evaluates to an empty string: KUBELET_KUBEADM_ARGS
Jan 16 18:53:18 capz-private-control-plane-zwk22 kubelet[1176]: Flag --pod-infra-container-image has been deprecated, will be removed in a future release. Image garbage collector will get sandbox image information from CRI.
Jan 16 18:53:18 capz-private-control-plane-zwk22 kubelet[1176]: I0116 18:53:18.188065    1176 server.go:211] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Jan 16 18:53:18 capz-private-control-plane-zwk22 kubelet[1176]: E0116 18:53:18.188366    1176 run.go:72] "command failed" err="failed to load kubelet config file, path: /var/lib/kubelet/config.yaml, error: failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory"
Jan 16 18:53:18 capz-private-control-plane-zwk22 systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
░░ Subject: Unit process exited
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ An ExecStart= process belonging to unit kubelet.service has exited.
░░
░░ The process' exit code is 'exited' and its exit status is 1.
Jan 16 18:53:18 capz-private-control-plane-zwk22 systemd[1]: kubelet.service: Failed with result 'exit-code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The unit kubelet.service has entered the 'failed' state with result 'exit-code'.
Jan 16 18:53:25 capz-private-control-plane-zwk22 systemd[1]: Stopped kubelet.service - kubelet: The Kubernetes Node Agent.
░░ Subject: A stop job for unit kubelet.service has finished
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ A stop job for unit kubelet.service has finished.
░░
░░ The job identifier is 1353 and the job result is done.
Jan 16 18:53:26 capz-private-control-plane-zwk22 systemd[1]: Started kubelet.service - kubelet: The Kubernetes Node Agent.
░░ Subject: A start job for unit kubelet.service has finished successfully
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ A start job for unit kubelet.service has finished successfully.
░░
░░ The job identifier is 1354.
Jan 16 18:53:26 capz-private-control-plane-zwk22 kubelet[2009]: Flag --container-runtime-endpoint has been deprecated, This parameter should be set via the config file specified by the Kubelet's --config flag. See https://kubernetes.io/docs/tasks/administer-cluster/kubelet-config-file/ for more information.
Jan 16 18:53:26 capz-private-control-plane-zwk22 kubelet[2009]: Flag --pod-infra-container-image has been deprecated, will be removed in a future release. Image garbage collector will get sandbox image information from CRI.
Jan 16 18:53:26 capz-private-control-plane-zwk22 kubelet[2009]: Flag --pod-infra-container-image has been deprecated, will be removed in a future release. Image garbage collector will get sandbox image information from CRI.
Jan 16 18:53:26 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:26.168067    2009 server.go:211] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Jan 16 18:53:26 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:26.675150    2009 server.go:491] "Kubelet version" kubeletVersion="v1.31.4"
Jan 16 18:53:26 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:26.675196    2009 server.go:493] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Jan 16 18:53:26 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:26.675608    2009 server.go:934] "Client rotation is on, will bootstrap in background"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.112445    2009 dynamic_cafile_content.go:160] "Starting controller" name="client-ca-bundle::/etc/kubernetes/pki/ca.crt"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.139963    2009 certificate_manager.go:562] "Unhandled Error" err="kubernetes.io/kube-apiserver-client-kubelet: Failed while requesting a signed certificate from the control plane: cannot create certificate signing request: Post \"https://172.19.2.4:6443/apis/certificates.k8s.io/v1/certificatesigningrequests\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.160358    2009 log.go:32] "RuntimeConfig from runtime service failed" err="rpc error: code = Unimplemented desc = unknown method RuntimeConfig for service runtime.v1.RuntimeService"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.160438    2009 server.go:1408] "CRI implementation should be updated to support RuntimeConfig when KubeletCgroupDriverFromCRI feature gate has been enabled. Falling back to using cgroupDriver from kubelet config."
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.181369    2009 server.go:749] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.181551    2009 swap_util.go:113] "Swap is on" /proc/swaps contents="Filename\t\t\t\tType\t\tSize\t\tUsed\t\tPriority"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.181747    2009 container_manager_linux.go:264] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.181802    2009 container_manager_linux.go:269] "Creating Container Manager object based on Node Config" nodeConfig={"NodeName":"capz-private-control-plane-zwk22","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":"nodefs.inodesFree","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"Signal":"imagefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.15},"GracePeriod":0,"MinReclaim":null},{"Signal":"imagefs.inodesFree","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"Signal":"memory.available","Operator":"LessThan","Value":{"Quantity":"100Mi","Percentage":0},"GracePeriod":0,"MinReclaim":null},{"Signal":"nodefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.1},"GracePeriod":0,"MinReclaim":null}],"QOSReserved":{},"CPUManagerPolicy":"none","CPUManagerPolicyOptions":null,"TopologyManagerScope":"container","CPUManagerReconcilePeriod":10000000000,"ExperimentalMemoryManagerPolicy":"None","ExperimentalMemoryManagerReservedMemory":null,"PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null,"CgroupVersion":2}
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.182127    2009 topology_manager.go:138] "Creating topology manager with none policy"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.182146    2009 container_manager_linux.go:300] "Creating device plugin manager"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.182315    2009 state_mem.go:36] "Initialized new in-memory state store"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.240054    2009 kubelet.go:408] "Attempting to sync node with API server"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.240134    2009 kubelet.go:303] "Adding static pod path" path="/etc/kubernetes/manifests"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.240230    2009 kubelet.go:314] "Adding apiserver pod source"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.246701    2009 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:27.254068    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Service: Get "https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.254139    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Service: failed to list *v1.Service: Get \"https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.269380    2009 kuberuntime_manager.go:262] "Container runtime initialized" containerRuntime="containerd" version="v1.7.20" apiVersion="v1"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:27.278744    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Node: Get "https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.278814    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Node: failed to list *v1.Node: Get \"https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.292867    2009 kubelet.go:837] "Not starting ClusterTrustBundle informer because we are in static kubelet mode"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:27.293159    2009 probe.go:272] Flexvolume plugin directory at /usr/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating.
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.309474    2009 server.go:1274] "Started kubelet"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.309636    2009 server.go:163] "Starting to listen" address="0.0.0.0" port=10250
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.309703    2009 ratelimit.go:55] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=10
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.310234    2009 server.go:236] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.318373    2009 server.go:460] "Adding debug handlers to kubelet server"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.357167    2009 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.357433    2009 dynamic_serving_content.go:135] "Starting controller" name="kubelet-server-cert-files::/var/lib/kubelet/pki/kubelet.crt::/var/lib/kubelet/pki/kubelet.key"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.357474    2009 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"capz-private-control-plane-zwk22\" not found"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.357676    2009 volume_manager.go:289] "Starting Kubelet Volume Manager"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.357921    2009 desired_state_of_world_populator.go:146] "Desired state populator starts to run"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.358088    2009 reconciler.go:26] "Reconciler: start to sync state"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.358092    2009 controller.go:145] "Failed to ensure lease exists, will retry" err="Get \"https://172.19.2.4:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/capz-private-control-plane-zwk22?timeout=10s\": dial tcp 172.19.2.4:6443: connect: connection refused" interval="200ms"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:27.358824    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.CSIDriver: Get "https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.358932    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.CSIDriver: failed to list *v1.CSIDriver: Get \"https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.366202    2009 factory.go:221] Registration of the systemd container factory successfully
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.366404    2009 factory.go:219] Registration of the crio container factory failed: Get "http://%2Fvar%2Frun%2Fcrio%2Fcrio.sock/info": dial unix /var/run/crio/crio.sock: connect: no such file or directory
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.367389    2009 kubelet.go:1478] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.367748    2009 factory.go:221] Registration of the containerd container factory successfully
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.376498    2009 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv4"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.378732    2009 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv6"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.378777    2009 status_manager.go:217] "Starting to sync pod status with apiserver"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.378798    2009 kubelet.go:2321] "Starting kubelet main sync loop"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.378852    2009 kubelet.go:2345] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:27.379481    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.RuntimeClass: Get "https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.379578    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.RuntimeClass: failed to list *v1.RuntimeClass: Get \"https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.389501    2009 cpu_manager.go:214] "Starting CPU manager" policy="none"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.389516    2009 cpu_manager.go:215] "Reconciling" reconcilePeriod="10s"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.389535    2009 state_mem.go:36] "Initialized new in-memory state store"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.382836    2009 event.go:368] "Unable to write event (may retry after sleeping)" err="Post \"https://172.19.2.4:6443/api/v1/namespaces/default/events\": dial tcp 172.19.2.4:6443: connect: connection refused" event="&Event{ObjectMeta:{capz-private-control-plane-zwk22.181b410d737d60b2  default    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},InvolvedObject:ObjectReference{Kind:Node,Namespace:,Name:capz-private-control-plane-zwk22,UID:capz-private-control-plane-zwk22,APIVersion:,ResourceVersion:,FieldPath:,},Reason:Starting,Message:Starting kubelet.,Source:EventSource{Component:kubelet,Host:capz-private-control-plane-zwk22,},FirstTimestamp:2025-01-16 18:53:27.309435058 +0000 UTC m=+1.200226049,LastTimestamp:2025-01-16 18:53:27.309435058 +0000 UTC m=+1.200226049,Count:1,Type:Normal,EventTime:0001-01-01 00:00:00 +0000 UTC,Series:nil,Action:,Related:nil,ReportingController:kubelet,ReportingInstance:capz-private-control-plane-zwk22,}"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.393137    2009 policy_none.go:49] "None policy: Start"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.393987    2009 memory_manager.go:170] "Starting memorymanager" policy="None"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.394017    2009 state_mem.go:35] "Initializing new in-memory state store"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.452198    2009 manager.go:513] "Failed to read data from checkpoint" checkpoint="kubelet_internal_checkpoint" err="checkpoint is not found"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.452374    2009 eviction_manager.go:189] "Eviction manager: starting control loop"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.452395    2009 container_log_manager.go:189] "Initializing container log rotate workers" workers=1 monitorPeriod="10s"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.452638    2009 plugin_manager.go:118] "Starting Kubelet Plugin Manager"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.454268    2009 eviction_manager.go:285] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"capz-private-control-plane-zwk22\" not found"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.553585    2009 kubelet_node_status.go:72] "Attempting to register node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.554041    2009 kubelet_node_status.go:95] "Unable to register node with API server" err="Post \"https://172.19.2.4:6443/api/v1/nodes\": dial tcp 172.19.2.4:6443: connect: connection refused" node="capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.558663    2009 controller.go:145] "Failed to ensure lease exists, will retry" err="Get \"https://172.19.2.4:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/capz-private-control-plane-zwk22?timeout=10s\": dial tcp 172.19.2.4:6443: connect: connection refused" interval="400ms"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.558853    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"k8s-certs\" (UniqueName: \"kubernetes.io/host-path/1d102d67558b57dd3b0ec2f6c6c31364-k8s-certs\") pod \"kube-apiserver-capz-private-control-plane-zwk22\" (UID: \"1d102d67558b57dd3b0ec2f6c6c31364\") " pod="kube-system/kube-apiserver-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.558924    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"etcd-data\" (UniqueName: \"kubernetes.io/host-path/8d3804150cb57cdfae19a628d5ce653e-etcd-data\") pod \"etcd-capz-private-control-plane-zwk22\" (UID: \"8d3804150cb57cdfae19a628d5ce653e\") " pod="kube-system/etcd-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.558973    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"ca-certs\" (UniqueName: \"kubernetes.io/host-path/1d102d67558b57dd3b0ec2f6c6c31364-ca-certs\") pod \"kube-apiserver-capz-private-control-plane-zwk22\" (UID: \"1d102d67558b57dd3b0ec2f6c6c31364\") " pod="kube-system/kube-apiserver-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559058    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"usr-share-ca-certificates\" (UniqueName: \"kubernetes.io/host-path/1d102d67558b57dd3b0ec2f6c6c31364-usr-share-ca-certificates\") pod \"kube-apiserver-capz-private-control-plane-zwk22\" (UID: \"1d102d67558b57dd3b0ec2f6c6c31364\") " pod="kube-system/kube-apiserver-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559144    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"etc-ca-certificates\" (UniqueName: \"kubernetes.io/host-path/b6bdb02e7d00b7f900c2ee06c24b928c-etc-ca-certificates\") pod \"kube-controller-manager-capz-private-control-plane-zwk22\" (UID: \"b6bdb02e7d00b7f900c2ee06c24b928c\") " pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559669    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"flexvolume-dir\" (UniqueName: \"kubernetes.io/host-path/b6bdb02e7d00b7f900c2ee06c24b928c-flexvolume-dir\") pod \"kube-controller-manager-capz-private-control-plane-zwk22\" (UID: \"b6bdb02e7d00b7f900c2ee06c24b928c\") " pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559707    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"k8s-certs\" (UniqueName: \"kubernetes.io/host-path/b6bdb02e7d00b7f900c2ee06c24b928c-k8s-certs\") pod \"kube-controller-manager-capz-private-control-plane-zwk22\" (UID: \"b6bdb02e7d00b7f900c2ee06c24b928c\") " pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559728    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"usr-share-ca-certificates\" (UniqueName: \"kubernetes.io/host-path/b6bdb02e7d00b7f900c2ee06c24b928c-usr-share-ca-certificates\") pod \"kube-controller-manager-capz-private-control-plane-zwk22\" (UID: \"b6bdb02e7d00b7f900c2ee06c24b928c\") " pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559749    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"usr-local-share-ca-certificates\" (UniqueName: \"kubernetes.io/host-path/1d102d67558b57dd3b0ec2f6c6c31364-usr-local-share-ca-certificates\") pod \"kube-apiserver-capz-private-control-plane-zwk22\" (UID: \"1d102d67558b57dd3b0ec2f6c6c31364\") " pod="kube-system/kube-apiserver-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559767    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"ca-certs\" (UniqueName: \"kubernetes.io/host-path/b6bdb02e7d00b7f900c2ee06c24b928c-ca-certs\") pod \"kube-controller-manager-capz-private-control-plane-zwk22\" (UID: \"b6bdb02e7d00b7f900c2ee06c24b928c\") " pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559786    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"usr-local-share-ca-certificates\" (UniqueName: \"kubernetes.io/host-path/b6bdb02e7d00b7f900c2ee06c24b928c-usr-local-share-ca-certificates\") pod \"kube-controller-manager-capz-private-control-plane-zwk22\" (UID: \"b6bdb02e7d00b7f900c2ee06c24b928c\") " pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559805    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"etcd-certs\" (UniqueName: \"kubernetes.io/host-path/8d3804150cb57cdfae19a628d5ce653e-etcd-certs\") pod \"etcd-capz-private-control-plane-zwk22\" (UID: \"8d3804150cb57cdfae19a628d5ce653e\") " pod="kube-system/etcd-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559834    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"etc-ca-certificates\" (UniqueName: \"kubernetes.io/host-path/1d102d67558b57dd3b0ec2f6c6c31364-etc-ca-certificates\") pod \"kube-apiserver-capz-private-control-plane-zwk22\" (UID: \"1d102d67558b57dd3b0ec2f6c6c31364\") " pod="kube-system/kube-apiserver-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559852    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kubeconfig\" (UniqueName: \"kubernetes.io/host-path/b6bdb02e7d00b7f900c2ee06c24b928c-kubeconfig\") pod \"kube-controller-manager-capz-private-control-plane-zwk22\" (UID: \"b6bdb02e7d00b7f900c2ee06c24b928c\") " pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.559871    2009 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kubeconfig\" (UniqueName: \"kubernetes.io/host-path/e01ca4c0e827cb6de47c4565491a2d51-kubeconfig\") pod \"kube-scheduler-capz-private-control-plane-zwk22\" (UID: \"e01ca4c0e827cb6de47c4565491a2d51\") " pod="kube-system/kube-scheduler-capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:27.755614    2009 kubelet_node_status.go:72] "Attempting to register node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.756487    2009 kubelet_node_status.go:95] "Unable to register node with API server" err="Post \"https://172.19.2.4:6443/api/v1/nodes\": dial tcp 172.19.2.4:6443: connect: connection refused" node="capz-private-control-plane-zwk22"
Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.960178    2009 controller.go:145] "Failed to ensure lease exists, will retry" err="Get \"https://172.19.2.4:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/capz-private-control-plane-zwk22?timeout=10s\": dial tcp 172.19.2.4:6443: connect: connection refused" interval="800ms"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:28.157431    2009 kubelet_node_status.go:72] "Attempting to register node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:28.157782    2009 kubelet_node_status.go:95] "Unable to register node with API server" err="Post \"https://172.19.2.4:6443/api/v1/nodes\": dial tcp 172.19.2.4:6443: connect: connection refused" node="capz-private-control-plane-zwk22"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:28.308629    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.CSIDriver: Get "https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:28.308722    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.CSIDriver: failed to list *v1.CSIDriver: Get \"https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:28.342507    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Node: Get "https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:28.342609    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Node: failed to list *v1.Node: Get \"https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:28.741075    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.RuntimeClass: Get "https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:28.741207    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.RuntimeClass: failed to list *v1.RuntimeClass: Get \"https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:28.753973    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Service: Get "https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:28.754055    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Service: failed to list *v1.Service: Get \"https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:28.760849    2009 controller.go:145] "Failed to ensure lease exists, will retry" err="Get \"https://172.19.2.4:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/capz-private-control-plane-zwk22?timeout=10s\": dial tcp 172.19.2.4:6443: connect: connection refused" interval="1.6s"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:28.958914    2009 kubelet_node_status.go:72] "Attempting to register node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:28 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:28.959304    2009 kubelet_node_status.go:95] "Unable to register node with API server" err="Post \"https://172.19.2.4:6443/api/v1/nodes\": dial tcp 172.19.2.4:6443: connect: connection refused" node="capz-private-control-plane-zwk22"
Jan 16 18:53:29 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:29.290689    2009 certificate_manager.go:562] "Unhandled Error" err="kubernetes.io/kube-apiserver-client-kubelet: Failed while requesting a signed certificate from the control plane: cannot create certificate signing request: Post \"https://172.19.2.4:6443/apis/certificates.k8s.io/v1/certificatesigningrequests\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:30.058115    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.CSIDriver: Get "https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:30.058191    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.CSIDriver: failed to list *v1.CSIDriver: Get \"https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:30.361687    2009 controller.go:145] "Failed to ensure lease exists, will retry" err="Get \"https://172.19.2.4:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/capz-private-control-plane-zwk22?timeout=10s\": dial tcp 172.19.2.4:6443: connect: connection refused" interval="3.2s"
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:30.560399    2009 kubelet_node_status.go:72] "Attempting to register node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:30.560849    2009 kubelet_node_status.go:95] "Unable to register node with API server" err="Post \"https://172.19.2.4:6443/api/v1/nodes\": dial tcp 172.19.2.4:6443: connect: connection refused" node="capz-private-control-plane-zwk22"
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:30.958452    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Node: Get "https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:30.958536    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Node: failed to list *v1.Node: Get \"https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:30 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:30.958934    2009 event.go:368] "Unable to write event (may retry after sleeping)" err="Post \"https://172.19.2.4:6443/api/v1/namespaces/default/events\": dial tcp 172.19.2.4:6443: connect: connection refused" event="&Event{ObjectMeta:{capz-private-control-plane-zwk22.181b410d737d60b2  default    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},InvolvedObject:ObjectReference{Kind:Node,Namespace:,Name:capz-private-control-plane-zwk22,UID:capz-private-control-plane-zwk22,APIVersion:,ResourceVersion:,FieldPath:,},Reason:Starting,Message:Starting kubelet.,Source:EventSource{Component:kubelet,Host:capz-private-control-plane-zwk22,},FirstTimestamp:2025-01-16 18:53:27.309435058 +0000 UTC m=+1.200226049,LastTimestamp:2025-01-16 18:53:27.309435058 +0000 UTC m=+1.200226049,Count:1,Type:Normal,EventTime:0001-01-01 00:00:00 +0000 UTC,Series:nil,Action:,Related:nil,ReportingController:kubelet,ReportingInstance:capz-private-control-plane-zwk22,}"
Jan 16 18:53:31 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:31.016110    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.RuntimeClass: Get "https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:31 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:31.016188    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.RuntimeClass: failed to list *v1.RuntimeClass: Get \"https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:31 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:31.625370    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Service: Get "https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:31 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:31.625427    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Service: failed to list *v1.Service: Get \"https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:33 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:33.563373    2009 controller.go:145] "Failed to ensure lease exists, will retry" err="Get \"https://172.19.2.4:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/capz-private-control-plane-zwk22?timeout=10s\": dial tcp 172.19.2.4:6443: connect: connection refused" interval="6.4s"
Jan 16 18:53:33 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:33.641868    2009 certificate_manager.go:562] "Unhandled Error" err="kubernetes.io/kube-apiserver-client-kubelet: Failed while requesting a signed certificate from the control plane: cannot create certificate signing request: Post \"https://172.19.2.4:6443/apis/certificates.k8s.io/v1/certificatesigningrequests\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:33 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:33.762593    2009 kubelet_node_status.go:72] "Attempting to register node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:33 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:33.762999    2009 kubelet_node_status.go:95] "Unable to register node with API server" err="Post \"https://172.19.2.4:6443/api/v1/nodes\": dial tcp 172.19.2.4:6443: connect: connection refused" node="capz-private-control-plane-zwk22"
Jan 16 18:53:34 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:34.761674    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.CSIDriver: Get "https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:34 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:34.761756    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.CSIDriver: failed to list *v1.CSIDriver: Get \"https://172.19.2.4:6443/apis/storage.k8s.io/v1/csidrivers?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:35 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:35.063977    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.RuntimeClass: Get "https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:35 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:35.064085    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.RuntimeClass: failed to list *v1.RuntimeClass: Get \"https://172.19.2.4:6443/apis/node.k8s.io/v1/runtimeclasses?limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:36 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:36.994678    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Node: Get "https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:36 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:36.994797    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Node: failed to list *v1.Node: Get \"https://172.19.2.4:6443/api/v1/nodes?fieldSelector=metadata.name%3Dcapz-private-control-plane-zwk22&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:37 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:37.454473    2009 eviction_manager.go:285] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"capz-private-control-plane-zwk22\" not found"
Jan 16 18:53:37 capz-private-control-plane-zwk22 kubelet[2009]: W0116 18:53:37.787789    2009 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Service: Get "https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0": dial tcp 172.19.2.4:6443: connect: connection refused
Jan 16 18:53:37 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:37.787925    2009 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Service: failed to list *v1.Service: Get \"https://172.19.2.4:6443/api/v1/services?fieldSelector=spec.clusterIP%21%3DNone&limit=500&resourceVersion=0\": dial tcp 172.19.2.4:6443: connect: connection refused" logger="UnhandledError"
Jan 16 18:53:40 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:40.164273    2009 kubelet_node_status.go:72] "Attempting to register node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:41 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:41.207008    2009 event.go:359] "Server rejected event (will not retry!)" err="namespaces \"default\" not found" event="&Event{ObjectMeta:{capz-private-control-plane-zwk22.181b410d737d60b2  default    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},InvolvedObject:ObjectReference{Kind:Node,Namespace:,Name:capz-private-control-plane-zwk22,UID:capz-private-control-plane-zwk22,APIVersion:,ResourceVersion:,FieldPath:,},Reason:Starting,Message:Starting kubelet.,Source:EventSource{Component:kubelet,Host:capz-private-control-plane-zwk22,},FirstTimestamp:2025-01-16 18:53:27.309435058 +0000 UTC m=+1.200226049,LastTimestamp:2025-01-16 18:53:27.309435058 +0000 UTC m=+1.200226049,Count:1,Type:Normal,EventTime:0001-01-01 00:00:00 +0000 UTC,Series:nil,Action:,Related:nil,ReportingController:kubelet,ReportingInstance:capz-private-control-plane-zwk22,}"
Jan 16 18:53:41 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:41.207447    2009 nodelease.go:49] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"capz-private-control-plane-zwk22\" not found" node="capz-private-control-plane-zwk22"
Jan 16 18:53:41 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:41.237360    2009 kubelet_node_status.go:75] "Successfully registered node" node="capz-private-control-plane-zwk22"
Jan 16 18:53:41 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:41.378700    2009 event.go:359] "Server rejected event (will not retry!)" err="namespaces \"default\" not found" event="&Event{ObjectMeta:{capz-private-control-plane-zwk22.181b410d78392f7d  default    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},InvolvedObject:ObjectReference{Kind:Node,Namespace:,Name:capz-private-control-plane-zwk22,UID:capz-private-control-plane-zwk22,APIVersion:,ResourceVersion:,FieldPath:,},Reason:NodeHasNoDiskPressure,Message:Node capz-private-control-plane-zwk22 status is now: NodeHasNoDiskPressure,Source:EventSource{Component:kubelet,Host:capz-private-control-plane-zwk22,},FirstTimestamp:2025-01-16 18:53:27.388852093 +0000 UTC m=+1.279642984,LastTimestamp:2025-01-16 18:53:27.388852093 +0000 UTC m=+1.279642984,Count:1,Type:Normal,EventTime:0001-01-01 00:00:00 +0000 UTC,Series:nil,Action:,Related:nil,ReportingController:kubelet,ReportingInstance:capz-private-control-plane-zwk22,}"
Jan 16 18:53:46 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:46.812920    2009 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"capz-private-control-plane-zwk22\" not found"
Jan 16 18:53:47 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:47.256972    2009 apiserver.go:52] "Watching apiserver"
Jan 16 18:53:47 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:53:47.358616    2009 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world"
Jan 16 18:54:51 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:54:51.448837    2009 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="kube-system/kube-apiserver-capz-private-control-plane-zwk22" podStartSLOduration=59.448790135 podStartE2EDuration="59.448790135s" podCreationTimestamp="2025-01-16 18:53:52 +0000 UTC" firstStartedPulling="0001-01-01 00:00:00 +0000 UTC" lastFinishedPulling="0001-01-01 00:00:00 +0000 UTC" observedRunningTime="2025-01-16 18:53:57.409853366 +0000 UTC m=+31.300644257" watchObservedRunningTime="2025-01-16 18:54:51.448790135 +0000 UTC m=+85.339581126"
Jan 16 18:54:59 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:54:59.389270    2009 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="kube-system/kube-scheduler-capz-private-control-plane-zwk22" podStartSLOduration=8.389243465 podStartE2EDuration="8.389243465s" podCreationTimestamp="2025-01-16 18:54:51 +0000 UTC" firstStartedPulling="0001-01-01 00:00:00 +0000 UTC" lastFinishedPulling="0001-01-01 00:00:00 +0000 UTC" observedRunningTime="2025-01-16 18:54:57.3906606 +0000 UTC m=+91.281451591" watchObservedRunningTime="2025-01-16 18:54:59.389243465 +0000 UTC m=+93.280034456"
Jan 16 18:55:07 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:55:07.392314    2009 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="kube-system/kube-controller-manager-capz-private-control-plane-zwk22" podStartSLOduration=10.392290365 podStartE2EDuration="10.392290365s" podCreationTimestamp="2025-01-16 18:54:57 +0000 UTC" firstStartedPulling="0001-01-01 00:00:00 +0000 UTC" lastFinishedPulling="0001-01-01 00:00:00 +0000 UTC" observedRunningTime="2025-01-16 18:55:07.392279465 +0000 UTC m=+101.283070456" watchObservedRunningTime="2025-01-16 18:55:07.392290365 +0000 UTC m=+101.283081256"
Jan 16 18:55:07 capz-private-control-plane-zwk22 kubelet[2009]: I0116 18:55:07.402164    2009 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="kube-system/etcd-capz-private-control-plane-zwk22" podStartSLOduration=8.402140739 podStartE2EDuration="8.402140739s" podCreationTimestamp="2025-01-16 18:54:59 +0000 UTC" firstStartedPulling="0001-01-01 00:00:00 +0000 UTC" lastFinishedPulling="0001-01-01 00:00:00 +0000 UTC" observedRunningTime="2025-01-16 18:55:07.402135639 +0000 UTC m=+101.292926530" watchObservedRunningTime="2025-01-16 18:55:07.402140739 +0000 UTC m=+101.292931730"
Jan 16 18:55:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:55:27.367462    2009 kubelet_node_status.go:447] "Node not becoming ready in time after startup"
Jan 16 19:08:37 capz-private-control-plane-zwk22 kubelet[2009]: E0116 19:08:37.724962    2009 kubelet.go:2902] "Container runtime network not ready" networkReady="NetworkReady=false reason:NetworkPluginNotReady message:Network plugin returns error: cni plugin not initialized"
Jan 16 19:08:41 capz-private-control-plane-zwk22 kubelet[2009]: E0116 19:08:41.840414    2009 certificate_manager.go:579] "Unhandled Error" err="kubernetes.io/kube-apiserver-client-kubelet: certificate request was not signed: timed out waiting for the condition" logger="UnhandledError"

[nawazkh]

Using the same node image, I can create and have a functioning cluster if I don't specify the API SERVER LB as type: Internal

What is the control plane replicas you are setting when using API SERVER LB as type: Internal ?
Could you retry if you are running into this issue when the control plane replica is 3 ?

[thiDucTran]

i retried with replica of 3.

• /var/log/cloud-init-output.log

[2025-03-11 15:17:38] [kubeconfig] Writing "admin.conf" kubeconfig file
[2025-03-11 15:17:38] [kubeconfig] Writing "super-admin.conf" kubeconfig file
[2025-03-11 15:17:39] [kubeconfig] Writing "kubelet.conf" kubeconfig file
[2025-03-11 15:17:39] [kubeconfig] Writing "controller-manager.conf" kubeconfig file
[2025-03-11 15:17:39] [kubeconfig] Writing "scheduler.conf" kubeconfig file
[2025-03-11 15:17:39] [etcd] Creating static Pod manifest for local etcd in "/etc/kubernetes/manifests"
[2025-03-11 15:17:39] [control-plane] Using manifest folder "/etc/kubernetes/manifests"
[2025-03-11 15:17:39] [control-plane] Creating static Pod manifest for "kube-apiserver"
[2025-03-11 15:17:39] [control-plane] Creating static Pod manifest for "kube-controller-manager"
[2025-03-11 15:17:39] [control-plane] Creating static Pod manifest for "kube-scheduler"
[2025-03-11 15:17:39] [kubelet-start] Writing kubelet environment file with flags to file "/var/lib/kubelet/kubeadm-flags.env"
[2025-03-11 15:17:39] [kubelet-start] Writing kubelet configuration to file "/var/lib/kubelet/config.yaml"
[2025-03-11 15:17:39] [kubelet-start] Starting the kubelet
[2025-03-11 15:17:40] [wait-control-plane] Waiting for the kubelet to boot up the control plane as static Pods from directory "/etc/kubernetes/manifests"
[2025-03-11 15:17:40] [kubelet-check] Waiting for a healthy kubelet at http://127.0.0.1:10248/healthz. This can take up to 4m0s
[2025-03-11 15:17:42] [kubelet-check] The kubelet is healthy after 1.502184819s
[2025-03-11 15:17:42] [api-check] Waiting for a healthy API server. This can take up to 20m0s
[2025-03-11 15:37:42] [api-check] The API server is not healthy after 20m0.001093528s
[2025-03-11 15:37:42]
[2025-03-11 15:37:42] Unfortunately, an error has occurred:
[2025-03-11 15:37:42]   context deadline exceeded
[2025-03-11 15:37:42]
[2025-03-11 15:37:42] This error is likely caused by:
[2025-03-11 15:37:42]   - The kubelet is not running
[2025-03-11 15:37:42]   - The kubelet is unhealthy due to a misconfiguration of the node in some way (required cgroups disabled)
[2025-03-11 15:37:42]
[2025-03-11 15:37:42] If you are on a systemd-powered system, you can try to troubleshoot the error with the following commands:
[2025-03-11 15:37:42]   - 'systemctl status kubelet'
[2025-03-11 15:37:42]   - 'journalctl -xeu kubelet'
[2025-03-11 15:37:42]
[2025-03-11 15:37:42] Additionally, a control plane component may have crashed or exited when started by the container runtime.
[2025-03-11 15:37:42] To troubleshoot, list all containers using your preferred container runtimes CLI.
[2025-03-11 15:37:42] Here is one example how you may list all running Kubernetes containers by using crictl:
[2025-03-11 15:37:42]   - 'crictl --runtime-endpoint unix:///var/run/containerd/containerd.sock ps -a | grep kube | grep -v pause'
[2025-03-11 15:37:42]   Once you have found the failing container, you can inspect its logs with:
[2025-03-11 15:37:42]   - 'crictl --runtime-endpoint unix:///var/run/containerd/containerd.sock logs CONTAINERID'
[2025-03-11 15:37:42] error execution phase wait-control-plane: could not initialize a Kubernetes cluster
[2025-03-11 15:37:42] To see the stack trace of this error execute with --v=5 or higher
[2025-03-11 15:37:42] 2025-03-11 15:37:42,363 - cc_scripts_user.py[WARNING]: Failed to run module scripts_user (scripts in /var/lib/cloud/instance/scripts)
[2025-03-11 15:37:42] 2025-03-11 15:37:42,364 - util.py[WARNING]: Running module scripts_user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py'>) failed
[2025-03-11 15:37:42] Cloud-init v. 24.3.1-0ubuntu0~24.04.2 finished at Tue, 11 Mar 2025 15:37:42 +0000. Datasource DataSourceAzure [seed=/dev/sr0].  Up 1247.62 seconds

• /var/log/waagent.log

2025-03-11T15:17:27.973498Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Requested extension state: enabled
2025-03-11T15:17:27.973952Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Enable extension: [bin/custom-script-shim enable]
2025-03-11T15:17:27.974358Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Executing command: /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/bin/custom-script-shim enable with environment variables: {"AZURE_GUEST_AGENT_UNINSTALL_CMD_EXIT_CODE": "NOT_RUN", "AZURE_GUEST_AGENT_EXTENSION_PATH": "/var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0", "AZURE_GUEST_AGENT_EXTENSION_VERSION": "1.0.0", "AZURE_GUEST_AGENT_WIRE_PROTOCOL_ADDRESS": "168.63.129.16", "ConfigSequenceNumber": "0", "AZURE_GUEST_AGENT_EXTENSION_SUPPORTED_FEATURES": "[{\"Key\": \"ExtensionTelemetryPipeline\", \"Value\": \"1.0\"}]"}
2025-03-11T15:17:29.978476Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Command: bin/custom-script-shim enable
[stdout]
Writing a placeholder status file indicating progress before forking: /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/status/0.status
+ nohup /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/bin/custom-script-extension enable
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event=start
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event=pre-check
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="comparing seqnum" path=mrseq
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="seqnum saved" path=mrseq
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="reading configuration"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="read configuration"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="validating json schema"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="json schema valid"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="parsing configuration json"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="parsed configuration json"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="validating configuration logically"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="validated configuration"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="creating output directory" path=/var/lib/waagent/custom-script/download/0
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="created output directory"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 files=0
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="executing command" output=/var/lib/waagent/custom-script/download/0
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="executing protected commandToExecute" output=/var/lib/waagent/custom-script/download/0
[stderr]
2025-03-11T15:17:29.982037Z INFO ExtHandler ExtHandler ProcessExtensionsGoalState completed [incarnation_2 4282 ms]

2025-03-11T15:17:30.014605Z INFO ExtHandler ExtHandler Extension status: [('Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping', 'transitioning')]
2025-03-11T15:17:30.015322Z INFO ExtHandler ExtHandler Looking for existing remote access users.
2025-03-11T15:17:30.135996Z INFO ExtHandler ExtHandler [HEARTBEAT] Agent WALinuxAgent-2.12.0.2 is running as the goal state agent [DEBUG HeartbeatCounter: 0;HeartbeatId: 7C3564F3-149F-4FD9-815E-F5A51A4DAB21;DroppedPackets: 0;UpdateGSErrors: 0;AutoUpdate: 1;UpdateMode: SelfUpdate;]
2025-03-11T15:22:25.084773Z INFO ExtHandler ExtHandler Extension status: [('Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping', 'error')]
2025-03-11T15:22:25.085381Z INFO ExtHandler ExtHandler All extensions in the goal state have reached a terminal state: [('Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping', 'error')]
2025-03-11T15:32:23.289596Z INFO Daemon Daemon Agent WALinuxAgent-2.12.0.2 launched with command '/usr/bin/python3 -u bin/WALinuxAgent-2.12.0.2-py3.9.egg -run-exthandlers' is successfully running
2025-03-11T15:47:35.916570Z INFO ExtHandler ExtHandler [HEARTBEAT] Agent WALinuxAgent-2.12.0.2 is running as the goal state agent [DEBUG HeartbeatCounter: 1;HeartbeatId: 7C3564F3-149F-4FD9-815E-F5A51A4DAB21;DroppedPackets: 0;UpdateGSErrors: 0;AutoUpdate: 1;UpdateMode: SelfUpdate;]

• /var/log/azure/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping/CommandExecution.log

2025-03-11T15:17:25.770600Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Target handler state: enabled [incarnation_2]
2025-03-11T15:17:25.770989Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] [Enable] current handler state is: notinstalled
2025-03-11T15:17:25.965350Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Initializing extension Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0
2025-03-11T15:17:25.966699Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Update settings file: 0.settings
2025-03-11T15:17:25.967124Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Install extension [bin/custom-script-shim install]
2025-03-11T15:17:25.967471Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Executing command: /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/bin/custom-script-shim install with environment variables: {"AZURE_GUEST_AGENT_UNINSTALL_CMD_EXIT_CODE": "NOT_RUN", "AZURE_GUEST_AGENT_EXTENSION_PATH": "/var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0", "AZURE_GUEST_AGENT_EXTENSION_VERSION": "1.0.0", "AZURE_GUEST_AGENT_WIRE_PROTOCOL_ADDRESS": "168.63.129.16", "ConfigSequenceNumber": "0", "AZURE_GUEST_AGENT_EXTENSION_SUPPORTED_FEATURES": "[{\"Key\": \"ExtensionTelemetryPipeline\", \"Value\": \"1.0\"}]"}
2025-03-11T15:17:27.972064Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Command: bin/custom-script-shim install
[stdout]
+ /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/bin/custom-script-extension install
time=2025-03-11T15:17:26Z version=v1.0.0/git@78a715c-dirty operation=install seq=0 event=start
time=2025-03-11T15:17:26Z version=v1.0.0/git@78a715c-dirty operation=install seq=0 status="not reported for operation (by design)"
time=2025-03-11T15:17:26Z version=v1.0.0/git@78a715c-dirty operation=install seq=0 event="migrate to mrseq" error="Can't find out seqnum from /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/status, not enough files."
time=2025-03-11T15:17:26Z version=v1.0.0/git@78a715c-dirty operation=install seq=0 event="created data dir" path=/var/lib/waagent/custom-script
time=2025-03-11T15:17:26Z version=v1.0.0/git@78a715c-dirty operation=install seq=0 event=installed
time=2025-03-11T15:17:26Z version=v1.0.0/git@78a715c-dirty operation=install seq=0 status="not reported for operation (by design)"
time=2025-03-11T15:17:26Z version=v1.0.0/git@78a715c-dirty operation=install seq=0 event=end
[stderr]
2025-03-11T15:17:27.973498Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Requested extension state: enabled
2025-03-11T15:17:27.973952Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Enable extension: [bin/custom-script-shim enable]
2025-03-11T15:17:27.974358Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Executing command: /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/bin/custom-script-shim enable with environment variables: {"AZURE_GUEST_AGENT_UNINSTALL_CMD_EXIT_CODE": "NOT_RUN", "AZURE_GUEST_AGENT_EXTENSION_PATH": "/var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0", "AZURE_GUEST_AGENT_EXTENSION_VERSION": "1.0.0", "AZURE_GUEST_AGENT_WIRE_PROTOCOL_ADDRESS": "168.63.129.16", "ConfigSequenceNumber": "0", "AZURE_GUEST_AGENT_EXTENSION_SUPPORTED_FEATURES": "[{\"Key\": \"ExtensionTelemetryPipeline\", \"Value\": \"1.0\"}]"}
2025-03-11T15:17:29.978476Z INFO ExtHandler [Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0] Command: bin/custom-script-shim enable
[stdout]
Writing a placeholder status file indicating progress before forking: /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/status/0.status
+ nohup /var/lib/waagent/Microsoft.Azure.ContainerUpstream.CAPZ.Linux.Bootstrapping-1.0.0/bin/custom-script-extension enable
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event=start
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event=pre-check
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="comparing seqnum" path=mrseq
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="seqnum saved" path=mrseq
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="reading configuration"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="read configuration"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="validating json schema"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="json schema valid"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="parsing configuration json"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="parsed configuration json"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="validating configuration logically"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="validated configuration"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="creating output directory" path=/var/lib/waagent/custom-script/download/0
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="created output directory"
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 files=0
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="executing command" output=/var/lib/waagent/custom-script/download/0
time=2025-03-11T15:17:28Z version=v1.0.0/git@78a715c-dirty operation=enable seq=0 event="executing protected commandToExecute" output=/var/lib/waagent/custom-script/download/0
[stderr]

afaik..it's the same deal..kubeadmcontrolplane is not initialized ..though i can confirm that API server is working as below

$ clusterctl  get kubeconfig capz-private >private.kubeconfig
$ export KUBECONFIG=/home/thitran/thiStuff/etcd/private.kubeconfig
$ kubectl get po -A
NAMESPACE     NAME                                                       READY   STATUS    RESTARTS   AGE
kube-system   etcd-capz-private-control-plane-r27wm                      1/1     Running   0          35m
kube-system   kube-apiserver-capz-private-control-plane-r27wm            1/1     Running   0          36m
kube-system   kube-controller-manager-capz-private-control-plane-r27wm   1/1     Running   0          36m
kube-system   kube-scheduler-capz-private-control-plane-r27wm            1/1     Running   0          36m

[nawazkh]

From your earlier comment #5372 (comment), the below line seems the most interesting to me

Jan 16 18:53:27 capz-private-control-plane-zwk22 kubelet[2009]: E0116 18:53:27.554041 2009 kubelet_node_status.go:95] "Unable to register node with API server" err="Post "https://172.19.2.4:6443/api/v1/nodes\": dial tcp 172.19.2.4:6443: connect: connection refused" node="capz-private-control-plane-zwk22"

Looks like the kubelet is unable to reach to the API Server over the the IP 172.19.2.4. I am guessing 172.19.2.4 is the IP of the control plane node.

---

Also, thank you for testing with Control plane replicas = 3 for the workload cluster.
It is quite strange to me that the kubelet is still failing with the workload cluster's controlplane replica = 3 with an APIServer LB = internal.

Could your scenario be running into hairpin problems by using APIServer type internal ?

---

To add more context: CAPZ.Linux.Bootstrapping is merely checking for presence of a sentinel file. Ref:

cluster-api-provider-azure/azure/defaults.go

Lines 316 to 352 in 66244df

	func GetBootstrappingVMExtension(osType string, cloud string, vmName string, cpuArchitectureType string) *ExtensionSpec {
	// currently, the bootstrap extension is only available in AzurePublicCloud.
	if osType == LinuxOS && cloud == PublicCloudName {
	// The command checks for the existence of the bootstrapSentinelFile on the machine, with retries and sleep between retries.
	// We set the version to 1.1 (will target 1.1.1) for arm64 machines and 1.0 for x64. This is due to a known issue with newer versions of
	// Go on Ubuntu 20.04. The issue is being tracked here: https://github.com/golang/go/issues/58550
	// TODO: Remove this once the issue is fixed, or when Ubuntu 20.04 is no longer supported.
	// We are using 1.1 instead of 1.1.1 for Arm64 as AzureAPI do not allow us to specify the full version.
	extensionVersion := "1.0"
	if cpuArchitectureType == string(armcompute.ArchitectureTypesArm64) {
	extensionVersion = "1.1"
	}
	return &ExtensionSpec{
	Name: BootstrappingExtensionLinux,
	VMName: vmName,
	Publisher: "Microsoft.Azure.ContainerUpstream",
	Version: extensionVersion,
	ProtectedSettings: map[string]string{
	"commandToExecute": LinuxBootstrapExtensionCommand,
	},
	}
	} else if osType == WindowsOS && cloud == PublicCloudName {
	// This command for the existence of the bootstrapSentinelFile on the machine, with retries and sleep between reties.
	// If the file is not present after the retries are exhausted the extension fails with return code '-2' - ERROR_FILE_NOT_FOUND.
	return &ExtensionSpec{
	Name: BootstrappingExtensionWindows,
	VMName: vmName,
	Publisher: "Microsoft.Azure.ContainerUpstream",
	Version: "1.0",
	ProtectedSettings: map[string]string{
	"commandToExecute": WindowsBootstrapExtensionCommand,
	},
	}
	}
	return nil
	}

And the sentinel file (Ref: https://cluster-api.sigs.k8s.io/developer/providers/contracts/bootstrap-config.html?highlight=%2Frun%2Fcluster-api%2Fbootstrap-success.complete#sentinel-file) is to be put up by the CABPK.
So I have a really strong feeling that something is blocking kubelet to be able to reach to the control-plane of the workload cluster thats causing this error.

[thiDucTran]

with controlplane replica = 1 isn't kubelet failing to call the same node that it on?

[nawazkh]

with controlplane replica = 1 isn't kubelet failing to call the same node that it on?

Only if the LB is of type internal.

---

Just to be sure, could we retry this with increased verbosity for CABPK? We shipped out newer templates with increased verbosity,

cluster-api-provider-azure/templates/cluster-template.yaml

Line 103 in 46be8d1

verbosity: 10

, but you could add verbosity: 10 to your current env to increase the verbosity. However, it would have to be on a newer deployment. Upgrading CAPZ to a newer version is not required for this test.