Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Open
thiDucTran opened this issue Jan 16, 2025 · 3 comments
Open

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

thiDucTran opened this issue Jan 16, 2025 · 3 comments
Labels
kind/bug Categorizes issue or PR as related to a bug. priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release.
Milestone
v1.20

Comments

@thiDucTran
Copy link
Contributor

thiDucTran commented Jan 16, 2025 •
edited
Loading

/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
  1. 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
    image
  • 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
@k8s-ci-robot k8s-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Jan 16, 2025
@thiDucTran
Copy link
Contributor Author

thiDucTran commented Jan 16, 2025 •
edited
Loading

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 nawazkh added the priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release. label Jan 23, 2025
@nawazkh
Copy link
Member

nawazkh commented Mar 6, 2025

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 ?

@nawazkh nawazkh moved this from Todo to Wait-On-Author in CAPZ Planning Mar 6, 2025
@thiDucTran
Copy link
Contributor Author

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 nawazkh added this to the v1.20 milestone Apr 10, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
kind/bug Categorizes issue or PR as related to a bug. priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release.
Projects
CAPZ Planning
Status: Wait-On-Author
Milestone
v1.20
Development

No branches or pull requests
3 participants
@k8s-ci-robot @nawazkh @thiDucTran