periodic-cluster-api-test-release-0-3 #1541070101330006016
Recent runs || View in Spyglass
| Result | FAILURE |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 4m18s |
| Revision | release-0.3 |
... skipping 774 lines ... I0626 14:47:01.785204 8401 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server" I0626 14:47:01.786125 8401 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate" I0626 14:47:01.786422 8401 server.go:199] controller-runtime/webhook "msg"="serving webhook server" "host"="" "port"=41433 I0626 14:47:01.786680 8401 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher" I0626 14:47:02.430893 8401 kubeadmconfig_controller.go:223] "msg"="Cluster infrastructure is not ready, waiting" "kind"="Machine" "kubeadmconfig"={"Namespace":"default","Name":"my-machine-config"} "name"="my-machine" "version"="109" [32m•[0mI0626 14:47:02.448315 8401 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" E0626 14:47:02.448401 8401 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed" E0626 14:47:02.448445 8401 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-872993848/tls.crt: no such file or directory" [1m[32mRan 1 of 1 Specs in 13.721 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m1 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (13.72s) PASS ok sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers 46.706s === RUN TestNewInitControlPlaneAdditionalFileEncodings --- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s) === RUN TestNewInitControlPlaneCommands ... skipping 316 lines ... === RUN Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined --- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s) --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s) --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s) === RUN Test_clusterctlClient_GetProviderComponents === RUN Test_clusterctlClient_GetProviderComponents/Pass === RUN Test_clusterctlClient_GetProviderComponents/Fail --- PASS: Test_clusterctlClient_GetProviderComponents (0.00s) --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s) --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s) === RUN Test_getComponentsByName_withEmptyVariables --- PASS: Test_getComponentsByName_withEmptyVariables (0.00s) === RUN Test_clusterctlClient_templateOptionsToVariables === RUN Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options) === RUN Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables) === RUN Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts) ... skipping 1406 lines ... === RUN TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil === RUN TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref I0626 14:46:45.664877 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config" I0626 14:46:45.667954 10454 cluster_controller_phases.go:76] "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test" === RUN TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion I0626 14:46:45.668371 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config" 2022/06/26 14:46:45 http: TLS handshake error from 127.0.0.1:43092: EOF === RUN TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_is_marked_ready_on_cluster I0626 14:46:45.671003 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config" === RUN TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_infrastructure_has_the_paused_annotation I0626 14:46:45.672202 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config" === RUN TestClusterReconcilePhases/reconcile_kubeconfig === RUN TestClusterReconcilePhases/reconcile_kubeconfig/cluster_not_provisioned,_apiEndpoint_is_not_set ... skipping 97 lines ... --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s) === RUN TestReconcileInfrastructure === RUN TestReconcileInfrastructure/new_machine,_infrastructure_config_ready I0626 14:46:45.717682 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" === RUN TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed I0626 14:46:45.719980 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" E0626 14:46:45.720368 10454 machine_controller_phases.go:246] "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-test\" in namespace \"default\", requeuing: requeue in 1s" === RUN TestReconcileInfrastructure/infrastructure_ref_is_paused I0626 14:46:45.720969 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" --- PASS: TestReconcileInfrastructure (0.00s) --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s) --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s) --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s) === RUN TestWatches I0626 14:46:45.893852 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={} E0626 14:46:45.896534 10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" I0626 14:46:45.908569 10454 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine" I0626 14:46:45.908658 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}} I0626 14:46:46.021178 10454 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine" I0626 14:46:46.021259 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}} I0626 14:46:46.121705 10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "noderef"="node-1" E0626 14:46:46.129503 10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" E0626 14:46:46.129558 10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" E0626 14:46:46.165963 10454 machine_controller_phases.go:246] controllers/Machine "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-created-78258\" in namespace \"test-machine-watches-mwchl\", requeuing: requeue in 1s" E0626 14:46:46.175975 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-created-78258\" in namespace \"test-machine-watches-mwchl\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-78258\" in namespace \"test-machine-watches-mwchl\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-78258" "namespace"="test-machine-watches-mwchl" --- PASS: TestWatches (0.53s) === RUN TestIndexMachineByNodeName === RUN TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef === RUN TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef --- PASS: TestIndexMachineByNodeName (0.00s) --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s) ... skipping 2 lines ... === RUN TestMachine_Reconcile/reconcile_create I0626 14:46:46.445520 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "count"=1 I0626 14:46:46.445592 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "descendants"="Worker machines: machine-created-78258" "indirect descendants count"=0 I0626 14:46:46.459411 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "count"=1 I0626 14:46:46.459464 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "descendants"="Worker machines: machine-created-78258" "indirect descendants count"=0 I0626 14:46:47.176474 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-kptkq" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"78ca5071-5d20-4ffd-b5ff-7472625fe2ad","apiVersion":"v1"} E0626 14:46:47.216950 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-78258\" not found" "controller"="machine" "name"="machine-created-78258" "namespace"="test-machine-watches-mwchl" E0626 14:46:48.331380 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-q8649\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-h6g5h\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-h6g5h: secrets \"machine-reconcile-h6g5h-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-q8649" "namespace"="default" I0626 14:46:49.331852 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-h6g5h" "machine"="machine-created-q8649" "namespace"="default" "cause"="noderef is nil" "node"=null I0626 14:46:49.356788 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-h6g5h" "machine"="machine-created-q8649" "namespace"="default" "cause"="noderef is nil" "node"=null I0626 14:46:49.396009 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-h6g5h" "machine"="machine-created-q8649" "namespace"="default" "cause"="noderef is nil" "node"=null E0626 14:46:49.420865 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-q8649\" not found" "controller"="machine" "name"="machine-created-q8649" "namespace"="default" --- PASS: TestMachine_Reconcile (3.18s) --- PASS: TestMachine_Reconcile/reconcile_create (3.18s) === RUN TestMachineFinalizer === RUN TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one === RUN TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer --- PASS: TestMachineFinalizer (0.00s) ... skipping 17 lines ... === RUN TestReconcileRequest/machine_should_be_created I0626 14:46:49.457108 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config" === RUN TestReconcileRequest/machine_should_be_updated I0626 14:46:49.461721 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config" === RUN TestReconcileRequest/machine_should_be_deleted I0626 14:46:49.466016 10454 machine_controller.go:305] "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null E0626 14:46:49.471037 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-h6g5h\" not found" "controller"="cluster" "name"="machine-reconcile-h6g5h" "namespace"="default" --- PASS: TestReconcileRequest (0.02s) --- PASS: TestReconcileRequest/machine_should_be_created (0.00s) --- PASS: TestReconcileRequest/machine_should_be_updated (0.00s) --- PASS: TestReconcileRequest/machine_should_be_deleted (0.01s) === RUN TestMachineConditions === RUN TestMachineConditions/all_conditions_true ... skipping 108 lines ... --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s) === RUN TestMachineHealthCheck_Reconcile === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist I0626 14:46:49.570466 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b9pjk" "namespace"="test-mhc-qv85q" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value I0626 14:46:49.612583 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} E0626 14:46:49.613697 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-xxts6\" not found" "cluster"="test-mhc-qv85q/test-cluster-xxts6" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present E0626 14:46:49.634473 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-b9pjk\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-b9pjk\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-b9pjk" "namespace"="test-mhc-qv85q" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist I0626 14:46:50.642211 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9kt78" "namespace"="test-mhc-v5vgj" I0626 14:46:50.642307 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b9pjk" "namespace"="test-mhc-qv85q" I0626 14:46:50.642339 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-42mgd" "namespace"="test-mhc-jhmhj" I0626 14:46:50.642369 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dkcxw" "namespace"="test-mhc-47l7r" I0626 14:46:50.669174 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0626 14:46:50.688074 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dkcxw" "namespace"="test-mhc-47l7r" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones I0626 14:46:50.700335 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dkcxw" "namespace"="test-mhc-47l7r" E0626 14:46:50.711210 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-zs2mb\" not found" "controller"="cluster" "name"="test-cluster-zs2mb" "namespace"="test-mhc-47l7r" E0626 14:46:50.711559 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-47l7r/test-cluster-zs2mb" I0626 14:46:50.840277 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbkcd" "namespace"="test-mhc-9bdtx" I0626 14:46:50.891463 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0626 14:46:50.916201 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbkcd" "namespace"="test-mhc-9bdtx" E0626 14:46:50.943245 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-9bdtx/test-cluster-jb2mb" === RUN TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy I0626 14:46:50.946400 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbkcd" "namespace"="test-mhc-9bdtx" I0626 14:46:50.962418 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" inframachine created: test-mhc-machine-infra-dk4dc I0626 14:46:50.983217 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} machine created: test-mhc-machine-dwh4p I0626 14:46:51.005889 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.012246 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.012548 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/" I0626 14:46:51.029270 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.029555 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/" I0626 14:46:51.039811 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.040131 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/" I0626 14:46:51.074845 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.075177 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/" I0626 14:46:51.092181 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.092578 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/" E0626 14:46:51.101996 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cj949, got []" "node"="test-mhc-node-cj949" node created: test-mhc-node-cj949 E0626 14:46:51.102441 10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-cj949" I0626 14:46:51.103021 10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" "noderef"="test-mhc-node-cj949" E0626 14:46:51.107438 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cj949, got []" "node"="test-mhc-node-cj949" E0626 14:46:51.107485 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cj949, got []" "node"="test-mhc-node-cj949" E0626 14:46:51.107834 10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-cj949" E0626 14:46:51.107876 10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-cj949" I0626 14:46:51.115580 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" inframachine created: test-mhc-machine-infra-bkm2k machine created: test-mhc-machine-ls8zp I0626 14:46:51.141380 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.146641 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.147834 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" ... skipping 98 lines ... I0626 14:46:51.375888 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.377973 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.380035 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.382146 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.386733 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.388545 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.388985 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-ls8zp/" E0626 14:46:51.459052 10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-25xz4" E0626 14:46:51.459157 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-25xz4, got []" "node"="test-mhc-node-25xz4" node created: test-mhc-node-25xz4 I0626 14:46:51.496520 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.496998 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-ls8zp/" I0626 14:46:51.500504 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.512001 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" Cleaning up nodes, machines and infra machines. I0626 14:46:51.524090 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.527316 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.527691 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/" I0626 14:46:51.546050 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:51.546607 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/" I0626 14:46:51.547099 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-ls8zp/" E0626 14:46:51.603805 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-brccc/test-cluster-mj26m" === RUN TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine E0626 14:46:51.613722 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="nodes \"test-mhc-node-25xz4\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" E0626 14:46:51.727797 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-machine-watches-mwchl/machine-reconcile-kptkq" inframachine created: test-mhc-machine-infra-hg7p4 machine created: test-mhc-machine-r2jgx E0626 14:46:51.787654 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-z4dtq\" not found" "controller"="machinehealthcheck" "name"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" E0626 14:46:52.614069 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:46:52.787969 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:52.813058 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0626 14:46:52.830575 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" I0626 14:46:52.830640 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:52.831641 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:52.833491 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" ... skipping 374 lines ... I0626 14:46:53.609476 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.611179 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.612864 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.614615 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.616282 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.617912 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" E0626 14:46:53.618670 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:46:53.619556 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.621149 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.622829 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.630225 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.631989 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:53.633678 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" ... skipping 492 lines ... I0626 14:46:54.613874 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:54.616307 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:54.618197 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:54.619915 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:54.621718 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:54.623551 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" E0626 14:46:54.629694 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:46:54.630614 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:54.631120 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-r2jgx/" I0626 14:46:54.640360 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:54.640624 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-r2jgx/" E0626 14:46:54.704144 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jcbhl, got []" "node"="test-mhc-node-jcbhl" node created: test-mhc-node-jcbhl I0626 14:46:54.711461 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" inframachine created: test-mhc-machine-infra-gclng I0626 14:46:54.729089 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" machine created: test-mhc-machine-wd58t I0626 14:46:54.737130 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" ... skipping 356 lines ... I0626 14:46:55.620130 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.622039 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.623973 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.625892 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.627826 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.629864 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" E0626 14:46:55.630282 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:46:55.631920 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.633821 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.635783 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.637733 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.639717 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:55.641610 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" ... skipping 446 lines ... I0626 14:46:56.662742 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.664253 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.665184 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.666253 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.667315 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.669571 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" E0626 14:46:56.674449 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:46:56.674566 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.675864 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.678894 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.689292 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.691432 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:56.693530 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" ... skipping 372 lines ... I0626 14:46:57.679355 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.681454 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.683616 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.684686 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.685687 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.687833 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" E0626 14:46:57.688333 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:46:57.688964 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.689289 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-wd58t/" I0626 14:46:57.708303 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.708707 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-wd58t/" E0626 14:46:57.761303 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5hzdg, got []" "node"="test-mhc-node-5hzdg" node created: test-mhc-node-5hzdg I0626 14:46:57.767843 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" inframachine created: test-mhc-machine-infra-zxb6l I0626 14:46:57.783084 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:57.786451 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" machine created: test-mhc-machine-f5bvk ... skipping 328 lines ... I0626 14:46:58.706458 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.709360 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.718202 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.720852 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.723141 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.725371 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" E0626 14:46:58.725677 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:46:58.727836 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.729094 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.730318 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.731560 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.732731 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:58.733936 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" ... skipping 336 lines ... I0626 14:46:59.757444 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.759029 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.761383 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.762985 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.765029 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.769641 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" E0626 14:46:59.773284 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:46:59.779052 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.780774 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.782488 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.787311 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.789804 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:46:59.793978 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" ... skipping 309 lines ... I0626 14:47:00.779378 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.782213 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.784651 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.787300 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.790660 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.792049 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.792441 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/" I0626 14:47:00.800966 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.801398 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/" E0626 14:47:00.810077 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" node created: test-mhc-node-zjmr4 E0626 14:47:00.829426 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zjmr4, got []" "node"="test-mhc-node-zjmr4" Cleaning up nodes, machines and infra machines. I0626 14:47:00.843104 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.843798 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/test-mhc-node-zjmr4" I0626 14:47:00.855381 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.855824 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/" Cleaning up nodes, machines and infra machines. I0626 14:47:00.864746 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.865244 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/" I0626 14:47:00.866501 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:00.866900 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-r2jgx/" I0626 14:47:00.894423 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "count"=2 I0626 14:47:00.894498 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "descendants"="Worker machines: test-mhc-machine-r2jgx,test-mhc-machine-wd58t,test-mhc-machine-f5bvk" "indirect descendants count"=1 I0626 14:47:00.897975 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "count"=2 I0626 14:47:00.898033 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "descendants"="Worker machines: test-mhc-machine-r2jgx,test-mhc-machine-wd58t,test-mhc-machine-f5bvk" "indirect descendants count"=1 === RUN TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy inframachine created: test-mhc-machine-infra-qwqkx machine created: test-mhc-machine-5mjxw I0626 14:47:01.061798 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/" E0626 14:47:01.064622 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-94th7\" not found" "controller"="machinehealthcheck" "name"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:01.811469 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qgnf6" "machine"="test-mhc-machine-wd58t" "namespace"="test-mhc-hhpfd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5hzdg"} E0626 14:47:01.845329 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wd58t\" not found" "controller"="machine" "name"="test-mhc-machine-wd58t" "namespace"="test-mhc-hhpfd" I0626 14:47:02.064898 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:02.079671 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0626 14:47:02.195509 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" I0626 14:47:02.195569 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:02.199999 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:02.200535 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:02.241188 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:02.322172 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:02.483188 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:02.806279 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" E0626 14:47:02.846326 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:47:03.449387 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:03.846788 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qgnf6" "machine"="test-mhc-machine-f5bvk" "namespace"="test-mhc-hhpfd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zjmr4"} E0626 14:47:03.885401 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f5bvk\" not found" "controller"="machine" "name"="test-mhc-machine-f5bvk" "namespace"="test-mhc-hhpfd" I0626 14:47:04.730452 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:04.886485 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qgnf6" "machine"="test-mhc-machine-r2jgx" "namespace"="test-mhc-hhpfd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jcbhl"} E0626 14:47:04.938038 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-r2jgx\" not found" "controller"="machine" "name"="test-mhc-machine-r2jgx" "namespace"="test-mhc-hhpfd" E0626 14:47:05.907860 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-hhpfd/test-cluster-qgnf6" E0626 14:47:05.938486 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:06.948857 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" E0626 14:47:06.973165 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:47:06.973195 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" node created: test-mhc-node-zltf8 E0626 14:47:07.017470 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zltf8, got []" "node"="test-mhc-node-zltf8" inframachine created: test-mhc-machine-infra-9jl62 I0626 14:47:07.037389 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" machine created: test-mhc-machine-drrpg I0626 14:47:07.053828 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:07.231073 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:07.236189 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:07.257271 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:07.298382 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:07.379590 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:07.540599 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:07.861929 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" E0626 14:47:07.973558 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:08.503242 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:08.985360 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:08.991626 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:09.000795 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:09.004634 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:09.011951 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" E0626 14:47:09.018681 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:47:09.018688 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:09.043977 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" E0626 14:47:09.058377 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ssxjb, got []" "node"="test-mhc-node-ssxjb" node created: test-mhc-node-ssxjb I0626 14:47:09.067474 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" inframachine created: test-mhc-machine-infra-c7bgm I0626 14:47:09.076966 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:09.085011 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" machine created: test-mhc-machine-29xs6 I0626 14:47:09.095276 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:09.102090 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:09.784821 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" E0626 14:47:10.019031 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:11.032626 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.059748 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.065525 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.075388 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.086934 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.093998 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" E0626 14:47:11.097628 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:47:11.098781 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.126262 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" node created: test-mhc-node-vkbvv E0626 14:47:11.202995 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vkbvv, got []" "node"="test-mhc-node-vkbvv" Cleaning up nodes, machines and infra machines. I0626 14:47:11.208822 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.219347 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" Cleaning up nodes, machines and infra machines. I0626 14:47:11.250438 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9rv2z" "namespace"="test-mhc-9brkx" "count"=2 I0626 14:47:11.250536 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9rv2z" "namespace"="test-mhc-9brkx" "descendants"="Worker machines: test-mhc-machine-5mjxw,test-mhc-machine-drrpg,test-mhc-machine-29xs6" "indirect descendants count"=1 ... skipping 3 lines ... inframachine created: test-mhc-machine-infra-r8x5q machine created: test-mhc-machine-5mbrg I0626 14:47:11.441439 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:11.459574 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0626 14:47:11.576761 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" I0626 14:47:11.576826 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" E0626 14:47:12.097935 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:13.098433 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9rv2z" "machine"="test-mhc-machine-5mjxw" "namespace"="test-mhc-9brkx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zltf8"} E0626 14:47:13.132328 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5mjxw\" not found" "controller"="machine" "name"="test-mhc-machine-5mjxw" "namespace"="test-mhc-9brkx" I0626 14:47:14.132925 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9rv2z" "machine"="test-mhc-machine-drrpg" "namespace"="test-mhc-9brkx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ssxjb"} E0626 14:47:14.173399 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-drrpg\" not found" "controller"="machine" "name"="test-mhc-machine-drrpg" "namespace"="test-mhc-9brkx" I0626 14:47:15.173843 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9rv2z" "machine"="test-mhc-machine-29xs6" "namespace"="test-mhc-9brkx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vkbvv"} E0626 14:47:15.219686 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-29xs6\" not found" "controller"="machine" "name"="test-mhc-machine-29xs6" "namespace"="test-mhc-9brkx" I0626 14:47:16.227778 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" E0626 14:47:16.233425 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:47:16.233634 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" E0626 14:47:16.268495 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-9brkx/test-cluster-9rv2z" E0626 14:47:16.311377 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-s28fj, got []" "node"="test-mhc-node-s28fj" node created: test-mhc-node-s28fj I0626 14:47:16.318946 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" inframachine created: test-mhc-machine-infra-vdc5x I0626 14:47:16.334071 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:16.343109 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" machine created: test-mhc-machine-9x9j5 I0626 14:47:16.349756 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" E0626 14:47:17.233822 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:18.247351 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.254359 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.263166 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.271531 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.280942 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.285870 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.301284 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.317771 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.362496 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" E0626 14:47:18.363232 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-npzd6, got []" "node"="test-mhc-node-npzd6" node created: test-mhc-node-npzd6 I0626 14:47:18.426737 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.430974 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" inframachine created: test-mhc-machine-infra-qnktr I0626 14:47:18.455897 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" machine created: test-mhc-machine-qmb7p ... skipping 7 lines ... Cleaning up nodes, machines and infra machines. I0626 14:47:18.566596 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fmhjl" "machine"="test-mhc-machine-qmb7p" "namespace"="test-mhc-4g4s6" "cause"="noderef is nil" "node"=null I0626 14:47:18.567778 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.573140 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" Cleaning up nodes, machines and infra machines. I0626 14:47:18.610230 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.610840 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-5mbrg/" I0626 14:47:18.644364 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.645102 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-5mbrg/" I0626 14:47:18.645441 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-9x9j5/" E0626 14:47:18.656074 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qmb7p\" not found" "controller"="machine" "name"="test-mhc-machine-qmb7p" "namespace"="test-mhc-4g4s6" I0626 14:47:18.666592 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" I0626 14:47:18.667236 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-5mbrg/" I0626 14:47:18.667649 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-9x9j5/" I0626 14:47:18.668720 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "count"=2 I0626 14:47:18.668791 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "descendants"="Worker machines: test-mhc-machine-5mbrg,test-mhc-machine-9x9j5" "indirect descendants count"=0 I0626 14:47:18.673468 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "count"=2 I0626 14:47:18.673525 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "descendants"="Worker machines: test-mhc-machine-5mbrg,test-mhc-machine-9x9j5" "indirect descendants count"=0 I0626 14:47:18.676622 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" === RUN TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout ... skipping 460 lines ... I0626 14:47:19.708359 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.709947 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.711719 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.713703 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.715290 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.716906 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" E0626 14:47:19.717846 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5mbrg\" not found" "controller"="machine" "name"="test-mhc-machine-5mbrg" "namespace"="test-mhc-4g4s6" I0626 14:47:19.718493 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.720189 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.721839 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.723448 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.725047 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:19.726759 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" ... skipping 513 lines ... I0626 14:47:20.755221 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.756910 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.758617 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.760216 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.761814 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.763780 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" E0626 14:47:20.764675 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9x9j5\" not found" "controller"="machine" "name"="test-mhc-machine-9x9j5" "namespace"="test-mhc-4g4s6" I0626 14:47:20.765504 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.767437 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.769155 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.770872 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.772716 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:20.774464 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" ... skipping 476 lines ... I0626 14:47:21.755247 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.757157 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.758960 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.760668 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.762423 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.764184 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" E0626 14:47:21.764966 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:47:21.765893 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.767636 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.769299 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.770984 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.772747 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:21.774465 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" ... skipping 528 lines ... I0626 14:47:22.765361 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.766932 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.768537 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.770024 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.771842 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.773772 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" E0626 14:47:22.775007 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:22.775341 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.775537 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/" I0626 14:47:22.782092 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.782317 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/" node created: test-mhc-node-qq7hh E0626 14:47:22.838127 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qq7hh, got []" "node"="test-mhc-node-qq7hh" E0626 14:47:22.838167 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qq7hh, got []" "node"="test-mhc-node-qq7hh" I0626 14:47:22.844960 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.860001 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.867176 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.867441 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/test-mhc-node-qq7hh" I0626 14:47:22.880396 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.880676 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/test-mhc-node-qq7hh" I0626 14:47:22.884747 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.885014 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/test-mhc-node-qq7hh" Cleaning up nodes, machines and infra machines. I0626 14:47:22.890999 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:22.891279 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/" I0626 14:47:22.901887 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dkt99" "namespace"="test-mhc-jbthn" "descendants"="Worker machines: test-mhc-machine-dnp6w" "indirect descendants count"=1 I0626 14:47:22.905485 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dkt99" "namespace"="test-mhc-jbthn" "descendants"="Worker machines: test-mhc-machine-dnp6w" "indirect descendants count"=1 === RUN TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted I0626 14:47:22.978326 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" "creating"=1 "need"=1 I0626 14:47:22.978383 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" I0626 14:47:22.986258 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-625t7-xvj5r\"" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" I0626 14:47:23.058062 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" I0626 14:47:23.064275 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:23.076889 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0626 14:47:23.194710 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" E0626 14:47:23.683174 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-4g4s6/test-cluster-fmhjl" I0626 14:47:23.775442 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dkt99" "machine"="test-mhc-machine-dnp6w" "namespace"="test-mhc-jbthn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-qq7hh"} E0626 14:47:23.834988 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dnp6w\" not found" "controller"="machine" "name"="test-mhc-machine-dnp6w" "namespace"="test-mhc-jbthn" I0626 14:47:24.195093 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:24.841830 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:24.842141 10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" I0626 14:47:24.845806 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:24.845937 10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" I0626 14:47:24.852396 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" ... skipping 4 lines ... I0626 14:47:24.860219 10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" I0626 14:47:24.865119 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:24.865147 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:24.868227 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:24.868267 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:25.196039 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:25.196390 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/" I0626 14:47:25.201494 10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" I0626 14:47:25.204509 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:25.204537 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:25.205041 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:25.205278 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/" I0626 14:47:25.210030 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:25.210064 10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" I0626 14:47:25.210339 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/" I0626 14:47:25.216378 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:25.216405 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:25.289009 10454 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" "machine"="mhc-ms-625t7-xvj5r" I0626 14:47:25.290159 10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "count"=1 I0626 14:47:25.290210 10454 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-625t7" I0626 14:47:25.292570 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4t7c9" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" "cause"="cluster is being deleted" "node"=null I0626 14:47:25.292579 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:25.292874 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/" I0626 14:47:25.297169 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:25.297353 10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/" I0626 14:47:25.299343 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" I0626 14:47:25.301084 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "descendants"="Machine sets: mhc-ms-625t7;Worker machines: mhc-ms-625t7-xvj5r" "indirect descendants count"=1 I0626 14:47:25.304730 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "descendants"="Worker machines: mhc-ms-625t7-xvj5r" "indirect descendants count"=1 === RUN TestMachineHealthCheck_Reconcile/when_a_machine_is_paused === RUN TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created I0626 14:47:25.320179 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4t7c9" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" "cause"="cluster is being deleted" "node"=null E0626 14:47:25.344034 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-625t7-xvj5r\" not found" "controller"="machine" "name"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" I0626 14:47:25.347068 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" inframachine created: test-mhc-machine-infra-2rp8c I0626 14:47:25.354730 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} machine created: test-mhc-machine-hw6ss I0626 14:47:25.365206 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:25.368576 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" ... skipping 587 lines ... I0626 14:47:26.348955 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.350046 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.350489 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.352138 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.353900 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" node created: test-mhc-node-6fvfg E0626 14:47:26.361178 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" E0626 14:47:26.361395 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" E0626 14:47:26.361406 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" I0626 14:47:26.362234 10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-hw6ss" "namespace"="test-mhc-nqhxt" "noderef"="test-mhc-node-6fvfg" E0626 14:47:26.365517 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" E0626 14:47:26.365592 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" E0626 14:47:26.365692 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" E0626 14:47:26.365736 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" E0626 14:47:26.366197 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" E0626 14:47:26.366282 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []" "node"="test-mhc-node-6fvfg" I0626 14:47:26.381507 10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "remediation request name"="test-mhc-machine-hw6ss" "target"="test-mhc-nqhxt/test-mhc-ghs98/test-mhc-machine-hw6ss/" I0626 14:47:26.388924 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.402482 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.409814 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.412210 10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request" "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "remediation request name"="test-mhc-machine-hw6ss" "target"="test-mhc-nqhxt/test-mhc-ghs98/test-mhc-machine-hw6ss/test-mhc-node-6fvfg" I0626 14:47:26.422515 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.426455 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" Cleaning up nodes, machines and infra machines. I0626 14:47:26.435111 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.441643 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" I0626 14:47:26.445809 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n8ggt" "namespace"="test-mhc-nqhxt" "descendants"="Worker machines: test-mhc-machine-hw6ss" "indirect descendants count"=1 I0626 14:47:26.449489 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n8ggt" "namespace"="test-mhc-nqhxt" "descendants"="Worker machines: test-mhc-machine-hw6ss" "indirect descendants count"=1 I0626 14:47:26.449513 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" === RUN TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted I0626 14:47:26.511039 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n8ggt" "machine"="test-mhc-machine-hw6ss" "namespace"="test-mhc-nqhxt" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-6fvfg","uid":"0faf5b5b-b7f8-4d7d-bdee-9c8b51115076","apiVersion":"v1"} E0626 14:47:26.538421 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-hw6ss\" not found" "controller"="machine" "name"="test-mhc-machine-hw6ss" "namespace"="test-mhc-nqhxt" I0626 14:47:26.566141 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" inframachine created: test-mhc-machine-infra-7czbf I0626 14:47:26.578292 10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} machine created: test-mhc-machine-jdh8q I0626 14:47:26.592395 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:26.593500 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" ... skipping 562 lines ... I0626 14:47:27.540183 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.541909 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.543426 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.544583 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.545280 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.547282 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" E0626 14:47:27.547583 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" I0626 14:47:27.549742 10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request" "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "remediation request name"="test-mhc-machine-jdh8q" "target"="test-mhc-zt7l8/test-mhc-6lgzl/test-mhc-machine-jdh8q/" I0626 14:47:27.558356 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" E0626 14:47:27.581811 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []" "node"="test-mhc-node-z9fmn" E0626 14:47:27.581966 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []" "node"="test-mhc-node-z9fmn" E0626 14:47:27.581966 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []" "node"="test-mhc-node-z9fmn" node created: test-mhc-node-z9fmn E0626 14:47:27.582232 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []" "node"="test-mhc-node-z9fmn" I0626 14:47:27.586217 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.598410 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.608915 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.611379 10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request" "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "remediation request name"="test-mhc-machine-jdh8q" "target"="test-mhc-zt7l8/test-mhc-6lgzl/test-mhc-machine-jdh8q/test-mhc-node-z9fmn" I0626 14:47:27.624853 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.626529 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.632657 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.646010 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.650239 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" Cleaning up nodes, machines and infra machines. I0626 14:47:27.656350 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" I0626 14:47:27.659448 10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request" "message"="" "reason"="NodeNotFound" "remediation request name"="test-mhc-machine-jdh8q" "target"="test-mhc-zt7l8/test-mhc-6lgzl/test-mhc-machine-jdh8q/" I0626 14:47:27.667975 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hwtmv" "namespace"="test-mhc-zt7l8" "descendants"="Worker machines: test-mhc-machine-jdh8q" "indirect descendants count"=1 I0626 14:47:27.671779 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hwtmv" "namespace"="test-mhc-zt7l8" "descendants"="Worker machines: test-mhc-machine-jdh8q" "indirect descendants count"=1 E0626 14:47:27.672512 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6lgzl\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" --- PASS: TestMachineHealthCheck_Reconcile (38.13s) --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s) --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.03s) --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.04s) --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.03s) --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.25s) ... skipping 10 lines ... --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s) machinehealthcheck_controller_test.go:933: skipping until made stable --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.15s) --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (1.22s) === RUN TestClusterToMachineHealthCheck === RUN TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster E0626 14:47:27.674392 10454 machinehealthcheck_controller.go:416] "msg"="expected a Cluster" "error"="incorrect type" "type"="handler.MapObject" === RUN TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace === RUN TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace === RUN TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace === RUN TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace --- PASS: TestClusterToMachineHealthCheck (0.00s) --- PASS: TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster (0.00s) --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace (0.00s) --- PASS: TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace (0.00s) --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace (0.00s) --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace (0.00s) === RUN TestMachineToMachineHealthCheck === RUN TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine E0626 14:47:27.675320 10454 machinehealthcheck_controller.go:445] "msg"="expected a Machine" "error"="incorrect type" "type"="handler.MapObject" === RUN TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace === RUN TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace === RUN TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace === RUN TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace --- PASS: TestMachineToMachineHealthCheck (0.00s) --- PASS: TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine (0.00s) --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace (0.00s) --- PASS: TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace (0.00s) --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace (0.00s) --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace (0.00s) === RUN TestNodeToMachineHealthCheck === RUN TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node E0626 14:47:27.676296 10454 machinehealthcheck_controller.go:474] "msg"="expected a Node" "error"="incorrect type" "type"="handler.MapObject" === RUN TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node E0626 14:47:27.676440 10454 machinehealthcheck_controller.go:480] "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got []" "node"="node1" === RUN TestNodeToMachineHealthCheck/when_two_Machines_exist_for_the_Node E0626 14:47:27.676693 10454 machinehealthcheck_controller.go:480] "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]" "node"="node1" === RUN TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace === RUN TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace === RUN TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace === RUN TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster --- PASS: TestNodeToMachineHealthCheck (0.00s) --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s) ... skipping 31 lines ... --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s) === RUN TestPatchTargets I0626 14:47:27.678474 10454 machinehealthcheck_controller.go:387] "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="" "target"="default/mhc/machine1/" I0626 14:47:27.678838 10454 machinehealthcheck_controller.go:387] "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="" "target"="default/mhc/machine2/" E0626 14:47:27.679821 10454 machinehealthcheck_controller.go:320] "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found" "machine"="machine1" --- PASS: TestPatchTargets (0.00s) === RUN TestGetTargetsFromMHC === RUN TestGetTargetsFromMHC/with_no_matching_machines === RUN TestGetTargetsFromMHC/when_a_machine's_node_is_missing === RUN TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector === RUN TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes ... skipping 26 lines ... --- PASS: TestMachineSetOwnerReference (0.00s) --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s) --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s) === RUN TestMachineSetReconcile === RUN TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion === RUN TestMachineSetReconcile/records_event_if_reconcile_fails E0626 14:47:27.685074 10454 machineset_controller.go:151] "msg"="Failed to reconcile MachineSet" "error"="failed to calculate MachineSet's Status: failed to calculate status for MachineSet default/machineset1: invalid label key \"--$-invalid\": name part must consist of alphanumeric characters, '-', '_' or '.', and must start and end with an alphanumeric character (e.g. 'MyName', or 'my.name', or '123-abc', regex used for validation is '([A-Za-z0-9][-A-Za-z0-9_.]*)?[A-Za-z0-9]')" "machineset"="machineset1" "namespace"="default" --- PASS: TestMachineSetReconcile (0.00s) --- PASS: TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion (0.00s) --- PASS: TestMachineSetReconcile/records_event_if_reconcile_fails (0.00s) === RUN TestMachineSetToMachines === RUN TestMachineSetToMachines/should_return_empty_request_when_controller_is_set === RUN TestMachineSetToMachines/should_return_nil_if_machine_has_no_owner_reference ... skipping 8 lines ... --- PASS: TestAdoptOrphan (0.00s) === RUN TestHasMatchingLabels === RUN TestHasMatchingLabels/machine_set_and_machine_have_matching_labels === RUN TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels === RUN TestHasMatchingLabels/machine_set_has_empty_selector === RUN TestHasMatchingLabels/machine_set_has_bad_selector E0626 14:47:27.686157 10454 machineset_controller.go:569] "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" --- PASS: TestHasMatchingLabels (0.00s) --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s) --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s) --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s) --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s) === RUN TestMachineToDelete ... skipping 65 lines ... I0626 14:47:27.747506 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-xhxbv-s45s6\"" "machineset"="ms-xhxbv" "namespace"="ms-test" I0626 14:47:27.747554 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-xhxbv" "namespace"="ms-test" I0626 14:47:27.757297 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-xhxbv-f2zhm\"" "machineset"="ms-xhxbv" "namespace"="ms-test" I0626 14:47:27.860038 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-xhxbv" "namespace"="ms-test" "creating"=1 "need"=2 I0626 14:47:27.860071 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-xhxbv" "namespace"="ms-test" I0626 14:47:27.870100 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-xhxbv-hhk4s\"" "machineset"="ms-xhxbv" "namespace"="ms-test" E0626 14:47:27.913951 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-jbthn/test-cluster-dkt99" E0626 14:47:27.969944 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:27.969948 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:27.970181 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:28.073279 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:28.073319 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:28.073322 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:28.073360 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:28.073460 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:28.073487 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []" "node"="ms-xhxbv-s45s6-89pmg" E0626 14:47:28.095118 10454 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-xhxbv-s45s6-89pmg for machine ms-test/ms-xhxbv-s45s6: the cache is not started, can not read objects" "machineset"="ms-xhxbv" "namespace"="ms-test" E0626 14:47:28.099896 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.099908 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.100036 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.102416 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.102460 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.102467 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.102486 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.102528 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" E0626 14:47:28.102578 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []" "node"="ms-xhxbv-hhk4s-fp9qm" I0626 14:47:28.218202 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2 [32m•[0mI0626 14:47:28.221588 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2 I0626 14:47:28.260156 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2 I0626 14:47:28.260212 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" I0626 14:47:28.269098 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-lwq6r-6657c7fddb-27b6t\"" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" I0626 14:47:28.269199 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" ... skipping 6 lines ... I0626 14:47:28.476665 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3 I0626 14:47:28.476713 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" I0626 14:47:28.505632 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-6657c7fddb-h5lcz\"" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" I0626 14:47:28.548124 10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hwtmv" "machine"="test-mhc-machine-jdh8q" "namespace"="test-mhc-zt7l8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-z9fmn"} I0626 14:47:28.586363 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1 I0626 14:47:28.586408 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" E0626 14:47:28.587348 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jdh8q\" not found" "controller"="machine" "name"="test-mhc-machine-jdh8q" "namespace"="test-mhc-zt7l8" I0626 14:47:28.602786 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-cdfc6fd6c-cxgp8\"" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" I0626 14:47:28.674142 10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" E0626 14:47:28.679779 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.679792 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.679867 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.682190 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.682293 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.682190 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.682331 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.682235 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.682361 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []" "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr" E0626 14:47:28.707370 10454 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr for machine md-test/md-lwq6r-cdfc6fd6c-cxgp8: the cache is not started, can not read objects" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" I0626 14:47:28.726481 10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2 I0626 14:47:28.726520 10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "delete-policy"="Random" I0626 14:47:28.730274 10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "machine"="md-lwq6r-6657c7fddb-h5lcz" I0626 14:47:28.837991 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2 I0626 14:47:28.838036 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" I0626 14:47:28.847613 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-cdfc6fd6c-5pvjd\"" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" E0626 14:47:28.917950 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:28.917992 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:28.918218 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:29.020941 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:29.020991 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:29.020941 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:29.021024 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:29.020941 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" E0626 14:47:29.021075 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []" "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k" I0626 14:47:29.078723 10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1 I0626 14:47:29.078758 10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "delete-policy"="Random" I0626 14:47:29.082298 10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "machine"="md-lwq6r-6657c7fddb-2crgd" I0626 14:47:29.097836 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3 I0626 14:47:29.097869 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" I0626 14:47:29.105179 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-cdfc6fd6c-4mzs5\"" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" E0626 14:47:29.138918 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.138918 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.139109 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.241351 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.241402 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.241413 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.241449 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.241788 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" E0626 14:47:29.241850 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []" "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj" I0626 14:47:29.273692 10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0 I0626 14:47:29.273803 10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "delete-policy"="Random" I0626 14:47:29.280704 10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "machine"="md-lwq6r-6657c7fddb-2pmts" I0626 14:47:29.414863 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1 I0626 14:47:29.414919 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" I0626 14:47:29.428592 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-74d45c49c5-wpk9x\"" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" E0626 14:47:29.512142 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.512157 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.512158 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.514954 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.514966 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.515005 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.515012 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.514965 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" E0626 14:47:29.515044 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []" "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp" I0626 14:47:29.546129 10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2 I0626 14:47:29.546170 10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random" I0626 14:47:29.551263 10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "machine"="md-lwq6r-cdfc6fd6c-4mzs5" E0626 14:47:29.606022 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:29.662267 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2 I0626 14:47:29.662318 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" I0626 14:47:29.671034 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-74d45c49c5-fzc8v\"" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" E0626 14:47:29.741368 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.741452 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.741452 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.744062 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.744104 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.744136 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.744168 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.744205 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" E0626 14:47:29.744248 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []" "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9" I0626 14:47:29.779958 10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1 I0626 14:47:29.780038 10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random" I0626 14:47:29.783192 10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "machine"="md-lwq6r-cdfc6fd6c-5pvjd" I0626 14:47:29.892180 10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3 I0626 14:47:29.892215 10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" I0626 14:47:29.902629 10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-74d45c49c5-2bz4z\"" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" E0626 14:47:29.997150 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:29.997388 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:29.997821 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:30.100446 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:30.100509 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:30.100447 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:30.100547 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:30.100595 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" E0626 14:47:30.100657 10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []" "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw" I0626 14:47:30.127504 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x,md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-cdfc6fd6c-cxgp8,md-lwq6r-6657c7fddb-27b6t" "indirect descendants count"=8 I0626 14:47:30.131102 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-cdfc6fd6c,md-lwq6r-74d45c49c5;Worker machines: md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-cdfc6fd6c-cxgp8,md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x" "indirect descendants count"=8 [32m•[0mI0626 14:47:30.132254 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" E0626 14:47:30.134366 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-lwq6r\" not found" "controller"="machinedeployment" "name"="md-lwq6r" "namespace"="md-test" I0626 14:47:30.134896 10454 machine_controller_phases.go:219] "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" I0626 14:47:30.134961 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" I0626 14:47:30.135046 10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0 I0626 14:47:30.135073 10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random" I0626 14:47:30.136347 10454 machine_controller_phases.go:278] "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" I0626 14:47:30.136379 10454 machine_controller_noderef.go:45] "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" ... skipping 15 lines ... I0626 14:47:30.150814 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" [32m•[0mI0626 14:47:30.152855 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" I0626 14:47:30.153814 10454 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" I0626 14:47:30.154769 10454 machine_controller_phases.go:278] "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" I0626 14:47:30.154812 10454 machine_controller_noderef.go:45] "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" [32m•[0mI0626 14:47:30.155673 10454 machine_controller.go:327] "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" E0626 14:47:30.157692 10454 machine_controller.go:494] "msg"="Error creating a remote client while deleting Machine, won't retry" "error"="failed to create REST configuration for Cluster default/test-cluster: invalid configuration: no configuration has been provided" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" [32m•[0m[32m•[0mE0626 14:47:30.279081 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-shs4p\" not found" "controller"="cluster" "name"="test1-shs4p" "namespace"="default" I0626 14:47:30.705192 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:30.705223 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:30.718193 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" I0626 14:47:30.718220 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" E0626 14:47:30.741942 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" E0626 14:47:31.294426 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-bh4bs/test-cluster-4t7c9" [32m•[0mI0626 14:47:31.394569 10454 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-f5zkb" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" I0626 14:47:31.508165 10454 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-f5zkb" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" E0626 14:47:31.511482 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" E0626 14:47:31.782427 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" E0626 14:47:32.526151 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-nqhxt/test-cluster-n8ggt" E0626 14:47:32.528473 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" [32m•[0mI0626 14:47:32.805442 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:32.805480 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:32.808271 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" I0626 14:47:32.808299 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" E0626 14:47:32.811650 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" E0626 14:47:33.540206 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-6qqdp\" not found" "controller"="cluster" "name"="test3-6qqdp" "namespace"="default" E0626 14:47:33.823000 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" E0626 14:47:34.540809 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" E0626 14:47:34.831167 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" I0626 14:47:35.556646 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2 E0626 14:47:35.556651 10454 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-zt7l8/test-cluster-hwtmv" E0626 14:47:35.557201 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" [32m•[0mI0626 14:47:35.835163 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:35.835195 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:35.838252 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" I0626 14:47:35.838283 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" E0626 14:47:35.841665 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" I0626 14:47:36.557728 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x" "indirect descendants count"=7 E0626 14:47:36.561496 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" E0626 14:47:36.846203 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" E0626 14:47:37.562256 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" E0626 14:47:37.850908 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" E0626 14:47:38.570038 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" [32m•[0mI0626 14:47:38.855457 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:38.855494 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:38.858678 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" I0626 14:47:38.858709 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" E0626 14:47:38.862110 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" E0626 14:47:39.570759 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" E0626 14:47:39.862445 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc" E0626 14:47:40.571461 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" E0626 14:47:40.866598 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" E0626 14:47:41.580271 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" E0626 14:47:41.870660 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" I0626 14:47:42.580670 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-hhk4s,ms-xhxbv-s45s6" "indirect descendants count"=2 E0626 14:47:42.581118 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" E0626 14:47:42.870977 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" I0626 14:47:43.581521 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x,md-lwq6r-74d45c49c5-2bz4z" "indirect descendants count"=7 E0626 14:47:43.582061 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" I0626 14:47:43.874665 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:43.874705 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:43.878100 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" I0626 14:47:43.878133 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" E0626 14:47:43.883281 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" E0626 14:47:44.582788 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" E0626 14:47:44.896429 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" E0626 14:47:45.583418 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" E0626 14:47:45.900686 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" E0626 14:47:46.584017 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" I0626 14:47:46.904367 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:46.904402 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" I0626 14:47:46.907426 10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" I0626 14:47:46.907452 10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" I0626 14:47:46.918591 10454 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dtbh8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" E0626 14:47:46.926519 10454 machine_controller_noderef.go:73] controllers/Machine "msg"="Failed to retrieve Node by ProviderID" "error"="the cache is not started, can not read objects" "machine"="test6-dtbh8" "namespace"="default" E0626 14:47:46.937918 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\", the cache is not started, can not read objects]" "controller"="machine" "name"="test6-dtbh8" "namespace"="default" E0626 14:47:47.584611 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" E0626 14:47:47.942221 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test" E0626 14:47:48.585187 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default" E0626 14:47:48.946409 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test" I0626 14:47:49.585654 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2 E0626 14:47:49.586161 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" I0626 14:47:49.959283 10454 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dtbh8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" I0626 14:47:49.959485 10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-dtbh8" "namespace"="default" "noderef"="id-node-1" E0626 14:47:49.968963 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="machine" "name"="test6-dtbh8" "namespace"="default" I0626 14:47:50.586629 10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x" "indirect descendants count"=7 E0626 14:47:50.590367 10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-6rsc4: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default" [90m------------------------------[0m [32m• [SLOW TEST:12.042 seconds][0m Cluster Reconciler [90m/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45[0m Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready [90m/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:248[0m [90m------------------------------[0m [1m[32mRan 16 of 16 Specs in 22.987 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m16 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestGinkgoSuite (22.99s) PASS Tearing down test suite I0626 14:47:50.674361 10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" I0626 14:47:50.674407 10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" I0626 14:47:50.674423 10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" I0626 14:47:50.674438 10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" I0626 14:47:50.674406 10454 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" I0626 14:47:50.674451 10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" I0626 14:47:50.674371 10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" E0626 14:47:50.701176 10454 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:40957/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1301&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:40957: connect: connection refused E0626 14:47:50.701177 10454 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:40957/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1301&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:40957: connect: connection refused E0626 14:47:50.701177 10454 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:40957/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1301&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:40957: connect: connection refused ok sigs.k8s.io/cluster-api/controllers 76.634s === RUN TestGetResourceFound --- PASS: TestGetResourceFound (0.00s) === RUN TestGetResourceNotFound --- PASS: TestGetResourceNotFound (0.00s) === RUN TestCloneTemplateResourceNotFound ... skipping 265 lines ... I0626 14:46:46.679462 10981 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={} [32m•[0mI0626 14:46:47.217431 10981 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" I0626 14:46:47.237470 10981 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}} I0626 14:46:47.337861 10981 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" I0626 14:46:47.337914 10981 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1 [32m•[0mI0626 14:46:47.515220 10981 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" E0626 14:46:49.542381 10981 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="cluster-cache-test-54rg8/test-cluster" [32m•[0mE0626 14:46:49.991815 10981 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="the server could not find the requested resource" "cluster"="cluster-cache-test-fn5z5/test-cluster" [32m•[0mE0626 14:46:50.523640 10981 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:35113/?timeout=50ms: dial tcp 127.0.0.1:35113: connect: connection refused" "cluster"="cluster-cache-test-tffhd/test-cluster" [32m•[0mE0626 14:46:50.736031 10981 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0626 14:46:50.736072 10981 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-431684687/tls.crt: no such file or directory" E0626 14:46:50.736089 10981 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed" E0626 14:46:50.736103 10981 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-431684687/tls.crt: no such file or directory" I0626 14:46:50.736119 10981 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" E0626 14:46:50.779754 10981 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1alpha3.Cluster: Get http://127.0.0.1:33287/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:33287: connect: connection refused [1m[32mRan 5 of 5 Specs in 14.814 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m5 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestGinkgoSuite (14.81s) PASS ok sigs.k8s.io/cluster-api/controllers/remote 14.930s ? sigs.k8s.io/cluster-api/controllers/remote/fake [no test files] ? sigs.k8s.io/cluster-api/controlplane/kubeadm [no test files] === RUN TestKubeadmControlPlaneDefault ... skipping 208 lines ... === RUN TestReconcileNoClusterOwnerRef I0626 14:46:57.244977 11517 controller.go:130] "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" --- PASS: TestReconcileNoClusterOwnerRef (0.00s) === RUN TestReconcileNoKCP --- PASS: TestReconcileNoKCP (0.00s) === RUN TestReconcileNoCluster E0626 14:46:57.246277 11517 controller.go:126] "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" --- PASS: TestReconcileNoCluster (0.00s) === RUN TestReconcilePaused I0626 14:46:57.246850 11517 controller.go:136] "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" I0626 14:46:57.246997 11517 controller.go:136] "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" --- PASS: TestReconcilePaused (0.00s) === RUN TestReconcileClusterNoEndpoints ... skipping 192 lines ... --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s) === RUN TestPreflightChecks === RUN TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass === RUN TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue I0626 14:47:11.323609 11517 scale.go:173] "msg"="Waiting for machines to be deleted" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Machines"="" === RUN TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue I0626 14:47:11.323711 11517 scale.go:212] "msg"="Waiting for control plane to pass preflight checks" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "failures"="machine reports APIServerPodHealthy condition is false (Error, )" === RUN TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass --- PASS: TestPreflightChecks (0.00s) --- PASS: TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass (0.00s) --- PASS: TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue (0.00s) --- PASS: TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue (0.00s) --- PASS: TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass (0.00s) ... skipping 18 lines ... === RUN TestAPIs Running Suite: Controller Suite =============================== Random Seed: [1m1656254804[0m Will run [1m1[0m of [1m1[0m specs E0626 14:47:11.342550 11517 controller.go:126] "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-qowh9e\" not found" "kubeadmControlPlane"="kcp-foo-qowh9e" "namespace"="test" [32m•[0m [1m[32mRan 1 of 1 Specs in 0.016 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m1 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (0.02s) === RUN TestKubeadmControlPlaneReconciler_upgradeControlPlane I0626 14:47:11.343567 11517 controller.go:246] "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-eqd2nm" "kubeadmControlPlane"="kcp-foo-eqd2nm" "namespace"="test" I0626 14:47:12.804313 11517 controller.go:331] "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-eqd2nm" "kubeadmControlPlane"="kcp-foo-eqd2nm" "namespace"="test" "needRollout"=["kcp-foo-eqd2nm-gvh8m"] I0626 14:47:12.804512 11517 scale.go:212] "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-eqd2nm" "kubeadmControlPlane"="kcp-foo-eqd2nm" "namespace"="test" "failures"="[machine kcp-foo-eqd2nm-lcsq7 does not have APIServerPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have ControllerManagerPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have SchedulerPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have EtcdPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have EtcdMemberHealthy condition]" --- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.46s) ... skipping 60 lines ... ================================== Random Seed: [1m1656254804[0m Will run [1m7[0m of [1m7[0m specs [32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m [1m[32mRan 7 of 7 Specs in 0.002 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m7 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestControlPlane (0.00s) === RUN TestHasUnhealthyMachine --- PASS: TestHasUnhealthyMachine (0.00s) === RUN TestNewFailureDomainPicker === RUN TestNewFailureDomainPicker/simple === RUN TestNewFailureDomainPicker/no_machines ... skipping 111 lines ... ======================================= Random Seed: [1m1656254804[0m Will run [1m7[0m of [1m7[0m specs [32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m [1m[32mRan 7 of 7 Specs in 0.001 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m7 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestMachineCollection (0.00s) === RUN TestUpdateEtcdConditions === RUN TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown === RUN TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines === RUN TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines === RUN TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition ... skipping 297 lines ... --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s) --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s) === RUN TestRemoveMachineFromKubeadmConfigMap === RUN TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil === RUN TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil === RUN TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0 E0626 14:46:59.594256 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:47:07.917365 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:47:16.903326 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:47:28.033542 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:47:44.506735 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:47:57.515376 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:48:15.162752 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:48:36.086035 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:49:07.102575 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E0626 14:49:52.259653 11484 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" === RUN TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0 === RUN TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0 === RUN TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0 --- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s) --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s) --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s) ... skipping 83 lines ... --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s) PASS E0626 14:49:52.268630 11484 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0626 14:49:52.268675 11484 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-417642536/tls.crt: no such file or directory" E0626 14:49:52.268690 11484 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0626 14:49:52.268705 11484 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-417642536/tls.crt: no such file or directory" I0626 14:49:52.269436 11484 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" ok sigs.k8s.io/cluster-api/controlplane/kubeadm/internal 188.106s === RUN TestEtcdMembers_WithErrors --- PASS: TestEtcdMembers_WithErrors (0.00s) === RUN TestEtcdMembers_WithSuccess --- PASS: TestEtcdMembers_WithSuccess (0.00s) ... skipping 288 lines ... I0626 14:47:04.898370 11826 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1 I0626 14:47:04.898643 11826 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}} I0626 14:47:04.999055 11826 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}} I0626 14:47:05.099620 11826 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" I0626 14:47:05.099704 11826 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1 I0626 14:47:05.201955 11826 clusterresourcesetbinding_controller.go:84] "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-umy3n4"} E0626 14:47:05.228096 11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default" [32m•[0mI0626 14:47:06.284854 11826 clusterresourcesetbinding_controller.go:84] "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-nazad5"} [32m•[0mE0626 14:47:06.329732 11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default" E0626 14:47:07.437386 11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default" E0626 14:47:08.462501 11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default" [32m•[0mE0626 14:47:09.571532 11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default" E0626 14:47:10.590758 11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset2\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset2" "namespace"="default" [32m•[0mE0626 14:47:11.601485 11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default" [32m•[0mI0626 14:47:11.606433 11826 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" E0626 14:47:11.606455 11826 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" I0626 14:47:11.606490 11826 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" E0626 14:47:11.606493 11826 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-688416601/tls.crt: no such file or directory" I0626 14:47:11.606506 11826 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" E0626 14:47:11.606522 11826 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0626 14:47:11.606539 11826 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-688416601/tls.crt: no such file or directory" [1m[32mRan 5 of 5 Specs in 19.468 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m5 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (19.47s) PASS ok sigs.k8s.io/cluster-api/exp/addons/controllers 19.532s ? sigs.k8s.io/cluster-api/exp/addons/controllers/predicates [no test files] === RUN TestMachinePoolDefault === RUN TestMachinePoolDefault/for_MachinePool ... skipping 61 lines ... --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s) --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s) --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s) === RUN TestReconcileMachinePoolInfrastructure === RUN TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready === RUN TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed E0626 14:46:56.770314 12034 machinepool_controller_phases.go:237] "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" === RUN TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused --- PASS: TestReconcileMachinePoolInfrastructure (0.00s) --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s) --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s) --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s) === RUN TestMachinePoolFinalizer ... skipping 95 lines ... [32m•[0mI0626 14:47:07.607924 12034 machinepool_controller_noderef.go:90] "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes" [32m•[0mI0626 14:47:07.645030 12034 machinepool_controller_noderef.go:90] "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes" [32m•[0m[32m•[0mI0626 14:47:07.647803 12034 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" [1m[32mRan 9 of 9 Specs in 10.815 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m9 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (10.82s) PASS ok sigs.k8s.io/cluster-api/exp/controllers 11.091s ? sigs.k8s.io/cluster-api/exp/util [no test files] ? sigs.k8s.io/cluster-api/feature [no test files] ? sigs.k8s.io/cluster-api/hack/boilerplate/test [no test files] ... skipping 266 lines ... --- PASS: TestGetFirstReasonAndMessage (0.00s) === RUN TestNewConditionsGroup --- PASS: TestNewConditionsGroup (0.00s) === RUN TestMergeRespectPriority === RUN TestMergeRespectPriority/aggregate_nil_list_return_nil === RUN TestMergeRespectPriority/aggregate_empty_list_return_nil === RUN TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error === RUN TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning === RUN TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info === RUN TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info === RUN TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown === RUN TestMergeRespectPriority/nil_conditions_are_ignored --- PASS: TestMergeRespectPriority (0.00s) --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s) --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s) --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s) --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s) --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s) --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s) --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s) --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s) === RUN TestNewPatch === RUN TestNewPatch/No_changes_return_empty_patch ... skipping 209 lines ... Patch Helper [90m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39[0m Should patch conditions [90m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:102[0m on a clusterv1.Cluster object [90m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:150[0m [91m[1mshould not return an error if there is an unresolvable conflict when force overwrite is enabled [It][0m [90m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:366[0m [91mExpected success, but got an error: <errors.aggregate | len:1, cap:1>: [ { ErrStatus: { TypeMeta: {Kind: "", APIVersion: ""}, ListMeta: { SelfLink: "", ... skipping 33 lines ... [90m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39[0m Should patch a clusterv1.Cluster [90m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:411[0m [91m[1mupdating both spec, status, and adding a condition [It][0m [90m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:550[0m [91mExpected success, but got an error: <errors.aggregate | len:1, cap:1>: [ { ErrStatus: { TypeMeta: {Kind: "", APIVersion: ""}, ListMeta: { SelfLink: "", ... skipping 29 lines ... [32m•[0mI0626 14:47:30.245897 15007 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" [91m[1mSummarizing 2 Failures:[0m [91m[1m[Fail] [0m[90mPatch Helper [0m[0mShould patch conditions [0m[90mon a clusterv1.Cluster object [0m[91m[1m[It] should not return an error if there is an unresolvable conflict when force overwrite is enabled [0m [37m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:392[0m [91m[1m[Fail] [0m[90mPatch Helper [0m[0mShould patch a clusterv1.Cluster [0m[91m[1m[It] updating both spec, status, and adding a condition [0m [37m/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:580[0m [1m[91mRan 14 of 14 Specs in 7.302 seconds[0m [1m[91mFAIL![0m -- [32m[1m12 Passed[0m | [91m[1m2 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- FAIL: TestPatch (7.30s) === RUN TestToUnstructured === RUN TestToUnstructured/with_a_typed_object === RUN TestToUnstructured/with_an_unstructured_object --- PASS: TestToUnstructured (0.00s) --- PASS: TestToUnstructured/with_a_typed_object (0.00s) --- PASS: TestToUnstructured/with_an_unstructured_object (0.00s) ... skipping 2 lines ... === RUN TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields === RUN TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields --- PASS: TestUnsafeFocusedUnstructured (0.00s) --- PASS: TestUnsafeFocusedUnstructured/focus=spec,_should_only_return_spec_and_common_fields (0.00s) --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields (0.00s) --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields (0.00s) FAIL FAIL sigs.k8s.io/cluster-api/util/patch 7.332s ? sigs.k8s.io/cluster-api/util/predicates [no test files] ? sigs.k8s.io/cluster-api/util/record [no test files] === RUN TestSortForCreate --- PASS: TestSortForCreate (0.00s) PASS ok sigs.k8s.io/cluster-api/util/resource 0.023s ... skipping 88 lines ... --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#01 (0.00s) --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#02 (0.00s) === RUN TestFromUnstructured --- PASS: TestFromUnstructured (0.00s) PASS ok sigs.k8s.io/cluster-api/util/yaml 0.030s FAIL make: *** [Makefile:116: test] Error 1