periodic-cluster-api-test-release-0-3 #1540526514561355776
Recent runs || View in Spyglass
| Result | FAILURE |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 4m19s |
| Revision | release-0.3 |
... skipping 777 lines ... I0625 02:47:00.104111 8281 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher" I0625 02:47:00.697984 8281 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•[0mI0625 02:47:00.707057 8281 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" [1m[32mRan 1 of 1 Specs in 13.396 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m1 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (13.40s) PASS ok sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers 43.549s === 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 1398 lines ... I0625 02:46:47.650844 10422 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}} I0625 02:46:47.650875 10422 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" I0625 02:46:47.650915 10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1 I0625 02:46:47.651197 10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1 I0625 02:46:47.651658 10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1 I0625 02:46:47.651728 10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1 2022/06/25 02:46:48 http: TLS handshake error from 127.0.0.1:56272: EOF === RUN TestClusterReconcilePhases === RUN TestClusterReconcilePhases/reconcile_infrastructure === RUN TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil === RUN TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref I0625 02:46:48.055666 10422 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" I0625 02:46:48.060473 10422 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" ... skipping 105 lines ... --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s) === RUN TestReconcileInfrastructure === RUN TestReconcileInfrastructure/new_machine,_infrastructure_config_ready I0625 02:46:48.084854 10422 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 I0625 02:46:48.094609 10422 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" E0625 02:46:48.095053 10422 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 I0625 02:46:48.095547 10422 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.01s) --- 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.01s) --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s) === RUN TestWatches I0625 02:46:48.379631 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={} E0625 02:46:48.382176 10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" I0625 02:46:48.386529 10422 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine" I0625 02:46:48.386606 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}} I0625 02:46:48.495260 10422 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine" I0625 02:46:48.495336 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}} I0625 02:46:48.595830 10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "noderef"="node-1" E0625 02:46:48.619464 10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" E0625 02:46:48.619507 10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" I0625 02:46:48.643384 10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "noderef"="node-1" E0625 02:46:48.664012 10422 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-wb6rc\" in namespace \"test-machine-watches-pf5l7\", requeuing: requeue in 1s" E0625 02:46:48.674494 10422 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-wb6rc\" in namespace \"test-machine-watches-pf5l7\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-wb6rc\" in namespace \"test-machine-watches-pf5l7\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" --- PASS: TestWatches (0.60s) === 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 I0625 02:46:48.892906 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "count"=1 I0625 02:46:48.892965 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "descendants"="Worker machines: machine-created-wb6rc" "indirect descendants count"=0 I0625 02:46:48.905492 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "count"=1 I0625 02:46:48.905551 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "descendants"="Worker machines: machine-created-wb6rc" "indirect descendants count"=0 I0625 02:46:49.674944 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-vvq2s" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"b139bddf-92ae-4411-9d90-0249261c1a82","apiVersion":"v1"} E0625 02:46:49.725761 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-wb6rc\" not found" "controller"="machine" "name"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" E0625 02:46:50.770099 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-7mrc5\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-lbskn\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-lbskn: secrets \"machine-reconcile-lbskn-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-7mrc5" "namespace"="default" I0625 02:46:51.770724 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lbskn" "machine"="machine-created-7mrc5" "namespace"="default" "cause"="noderef is nil" "node"=null I0625 02:46:51.803807 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lbskn" "machine"="machine-created-7mrc5" "namespace"="default" "cause"="noderef is nil" "node"=null I0625 02:46:51.952086 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lbskn" "machine"="machine-created-7mrc5" "namespace"="default" "cause"="noderef is nil" "node"=null E0625 02:46:51.979591 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-7mrc5\" not found" "controller"="machine" "name"="machine-created-7mrc5" "namespace"="default" --- PASS: TestMachine_Reconcile (3.30s) --- PASS: TestMachine_Reconcile/reconcile_create (3.30s) === 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 6 lines ... === RUN TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set I0625 02:46:52.001802 10422 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config" I0625 02:46:52.001966 10422 machine_controller_noderef.go:45] "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" === RUN TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner I0625 02:46:52.004569 10422 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config" I0625 02:46:52.004794 10422 machine_controller_noderef.go:45] "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" E0625 02:46:52.012566 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-lbskn\" not found" "controller"="cluster" "name"="machine-reconcile-lbskn" "namespace"="default" --- PASS: TestMachineOwnerReference (0.02s) --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s) --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s) --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s) === RUN TestReconcileRequest === RUN TestReconcileRequest/machine_should_be_created ... skipping 118 lines ... --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s) --- PASS: TestMachineDeploymentSyncStatus/scaling_up (0.00s) === RUN TestMachineHealthCheck_Reconcile === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist I0625 02:46:52.186582 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-84lht" "namespace"="test-mhc-x2dc2" I0625 02:46:52.211962 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} E0625 02:46:52.212893 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-x9cvl\" not found" "cluster"="test-mhc-x2dc2/test-cluster-x9cvl" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value E0625 02:46:52.216218 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-84lht\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-84lht\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-84lht" "namespace"="test-mhc-x2dc2" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist I0625 02:46:53.217786 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-84lht" "namespace"="test-mhc-x2dc2" I0625 02:46:53.217939 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwszn" "namespace"="test-mhc-xwn2h" I0625 02:46:53.217979 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zxs5q" "namespace"="test-mhc-fcfxw" I0625 02:46:53.218013 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cj6kd" "namespace"="test-mhc-rj9v4" I0625 02:46:53.239120 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0625 02:46:53.271827 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cj6kd" "namespace"="test-mhc-rj9v4" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones I0625 02:46:53.328442 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cj6kd" "namespace"="test-mhc-rj9v4" E0625 02:46:53.342450 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-rj9v4/test-cluster-nx55r" E0625 02:46:53.345930 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-nx55r\" not found" "controller"="cluster" "name"="test-cluster-nx55r" "namespace"="test-mhc-rj9v4" I0625 02:46:53.456098 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svq6k" "namespace"="test-mhc-wzwtv" I0625 02:46:53.472052 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0625 02:46:53.491251 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svq6k" "namespace"="test-mhc-wzwtv" E0625 02:46:53.573751 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-wzwtv/test-cluster-7bxrb" I0625 02:46:53.579574 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svq6k" "namespace"="test-mhc-wzwtv" === RUN TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy I0625 02:46:53.608516 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" inframachine created: test-mhc-machine-infra-mnjnz I0625 02:46:53.620017 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} machine created: test-mhc-machine-5hplm I0625 02:46:53.656362 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.660622 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.661428 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.661611 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.668802 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.669032 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.678504 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.678800 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.687537 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.687810 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.693342 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.693609 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.704203 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.704470 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.712406 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.712670 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" node created: test-mhc-node-8chs6 E0625 02:46:53.744621 10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-8chs6" E0625 02:46:53.744858 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8chs6, got []" "node"="test-mhc-node-8chs6" I0625 02:46:53.752589 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" inframachine created: test-mhc-machine-infra-xxvzb machine created: test-mhc-machine-7twhq I0625 02:46:53.771311 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.789729 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.790114 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" I0625 02:46:53.805183 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.805550 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" I0625 02:46:53.819199 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.820511 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" I0625 02:46:53.838844 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.839276 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" I0625 02:46:53.845381 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.845944 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" E0625 02:46:53.868485 10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-knfw9" E0625 02:46:53.868485 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-knfw9, got []" "node"="test-mhc-node-knfw9" I0625 02:46:53.868893 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" node created: test-mhc-node-knfw9 I0625 02:46:53.869274 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" I0625 02:46:53.873106 10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" "noderef"="test-mhc-node-knfw9" E0625 02:46:53.876669 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-knfw9, got []" "node"="test-mhc-node-knfw9" E0625 02:46:53.876721 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-knfw9, got []" "node"="test-mhc-node-knfw9" E0625 02:46:53.876923 10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-knfw9" E0625 02:46:53.876961 10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-knfw9" I0625 02:46:53.883486 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.883876 10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" I0625 02:46:53.889940 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.906522 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" Cleaning up nodes, machines and infra machines. I0625 02:46:53.916409 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.916843 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.935437 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:53.935859 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/" I0625 02:46:53.936277 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/" E0625 02:46:53.961527 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-vq5f2/test-cluster-zrd25" === RUN TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine inframachine created: test-mhc-machine-infra-vz66j machine created: test-mhc-machine-dcx7x E0625 02:46:54.094321 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-vcjgs\" not found" "controller"="machinehealthcheck" "name"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" E0625 02:46:54.142949 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" E0625 02:46:54.358637 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-machine-watches-pf5l7/machine-reconcile-vvq2s" I0625 02:46:55.094623 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:55.131285 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} E0625 02:46:55.144609 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:46:55.157492 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" I0625 02:46:55.157672 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:55.158524 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:55.165358 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:55.168687 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:55.174015 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" ... skipping 444 lines ... I0625 02:46:56.152928 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.154740 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.156550 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.157655 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.158714 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.160491 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" E0625 02:46:56.161977 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:46:56.162154 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.162691 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.162976 10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-dcx7x/" I0625 02:46:56.173549 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:56.173781 10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-dcx7x/" E0625 02:46:56.215574 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hkdgc, got []" "node"="test-mhc-node-hkdgc" node created: test-mhc-node-hkdgc I0625 02:46:56.221906 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" inframachine created: test-mhc-machine-infra-wtfft I0625 02:46:56.236044 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" machine created: test-mhc-machine-zhl5z I0625 02:46:56.249191 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" ... skipping 358 lines ... I0625 02:46:57.150816 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.152739 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.154604 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.156455 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.158355 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.160417 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" E0625 02:46:57.162248 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:46:57.162348 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.164166 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.166027 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.167889 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.169820 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:57.171961 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" ... skipping 405 lines ... I0625 02:46:58.188174 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.190388 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.192599 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.193655 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.195837 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.198117 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" E0625 02:46:58.198793 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:46:58.199686 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.200781 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.201855 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.211050 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.212579 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:58.213630 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" ... skipping 385 lines ... I0625 02:46:59.198274 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.200582 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.204214 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.207106 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.208131 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.210172 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.210657 10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-zhl5z/" E0625 02:46:59.211632 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:46:59.230158 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.231586 10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-zhl5z/" E0625 02:46:59.261807 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jgzrp, got []" "node"="test-mhc-node-jgzrp" node created: test-mhc-node-jgzrp I0625 02:46:59.268967 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" inframachine created: test-mhc-machine-infra-7ll7w machine created: test-mhc-machine-5wmg6 I0625 02:46:59.287179 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:46:59.291982 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" ... skipping 301 lines ... I0625 02:47:00.209724 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.212379 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.214723 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.221696 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.224454 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.226304 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" E0625 02:47:00.226502 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:00.227517 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.228789 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.230003 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.231701 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.233401 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:00.235029 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" ... skipping 324 lines ... I0625 02:47:01.272431 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.273757 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.275171 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.276479 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.277782 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.283845 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" E0625 02:47:01.284158 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:47:01.292890 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.294543 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.298393 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.303617 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.306942 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:01.309496 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" ... skipping 287 lines ... I0625 02:47:02.280542 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.289374 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.293243 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.295642 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.298331 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.307153 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.307574 10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/" E0625 02:47:02.308243 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8s7g9, got []" "node"="test-mhc-node-8s7g9" node created: test-mhc-node-8s7g9 E0625 02:47:02.311121 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:02.319269 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.319851 10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/" I0625 02:47:02.328561 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.329043 10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/test-mhc-node-8s7g9" Cleaning up nodes, machines and infra machines. Cleaning up nodes, machines and infra machines. I0625 02:47:02.349029 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.349498 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/" I0625 02:47:02.373964 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.374485 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-jgrsc/test-mhc-64wp4/test-mhc-machine-dcx7x/" I0625 02:47:02.391845 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/" I0625 02:47:02.410348 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "count"=2 I0625 02:47:02.410430 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "descendants"="Worker machines: test-mhc-machine-dcx7x,test-mhc-machine-zhl5z,test-mhc-machine-5wmg6" "indirect descendants count"=1 === RUN TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy E0625 02:47:02.420487 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-64wp4\" not found" "controller"="machinehealthcheck" "name"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:02.435208 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "count"=2 I0625 02:47:02.435304 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "descendants"="Worker machines: test-mhc-machine-dcx7x,test-mhc-machine-zhl5z,test-mhc-machine-5wmg6" "indirect descendants count"=1 inframachine created: test-mhc-machine-infra-h6cdp machine created: test-mhc-machine-njglz I0625 02:47:03.311699 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-22vp6" "machine"="test-mhc-machine-zhl5z" "namespace"="test-mhc-jgrsc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jgzrp"} E0625 02:47:03.351310 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zhl5z\" not found" "controller"="machine" "name"="test-mhc-machine-zhl5z" "namespace"="test-mhc-jgrsc" I0625 02:47:03.420724 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" I0625 02:47:03.420867 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:03.439446 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0625 02:47:03.556424 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:03.561553 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:03.582257 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:03.623104 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:03.704104 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:03.865027 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:04.185932 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:04.351666 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:47:04.826944 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:05.352173 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-22vp6" "machine"="test-mhc-machine-5wmg6" "namespace"="test-mhc-jgrsc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8s7g9"} E0625 02:47:05.390590 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5wmg6\" not found" "controller"="machine" "name"="test-mhc-machine-5wmg6" "namespace"="test-mhc-jgrsc" I0625 02:47:06.107980 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:06.391184 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-22vp6" "machine"="test-mhc-machine-dcx7x" "namespace"="test-mhc-jgrsc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hkdgc"} E0625 02:47:06.450224 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dcx7x\" not found" "controller"="machine" "name"="test-mhc-machine-dcx7x" "namespace"="test-mhc-jgrsc" E0625 02:47:07.437203 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-jgrsc/test-cluster-22vp6" E0625 02:47:07.450559 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:08.458400 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:08.461624 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:47:08.462401 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:08.481887 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:08.486188 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vx6kq, got []" "node"="test-mhc-node-vx6kq" node created: test-mhc-node-vx6kq I0625 02:47:08.492368 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" inframachine created: test-mhc-machine-infra-5pm8p machine created: test-mhc-machine-plhqm I0625 02:47:08.528206 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:08.540275 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:08.549917 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:08.560034 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:08.601519 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:08.683820 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:08.845104 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:09.166504 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:09.462121 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:09.807766 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.475427 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.480535 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.490280 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.498516 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.513016 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.518848 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:10.520042 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" node created: test-mhc-node-4q9kd I0625 02:47:10.541346 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:10.543358 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4q9kd, got []" "node"="test-mhc-node-4q9kd" I0625 02:47:10.546758 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" inframachine created: test-mhc-machine-infra-twvxb machine created: test-mhc-machine-6ctb2 I0625 02:47:10.560272 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.561895 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.572181 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:10.577393 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:11.089070 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:11.520449 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:12.534003 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:12.550589 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:12.558644 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:12.574989 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:12.580776 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:12.586914 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:12.591880 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:12.594947 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:47:12.607493 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" E0625 02:47:12.680915 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pnwld, got []" "node"="test-mhc-node-pnwld" node created: test-mhc-node-pnwld I0625 02:47:12.689871 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" Cleaning up nodes, machines and infra machines. I0625 02:47:12.699521 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" Cleaning up nodes, machines and infra machines. I0625 02:47:12.732739 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8j4q9" "namespace"="test-mhc-n4s2v" "count"=2 ... skipping 4 lines ... I0625 02:47:12.842006 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" I0625 02:47:12.861965 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" inframachine created: test-mhc-machine-infra-2tvnq machine created: test-mhc-machine-jnlv5 I0625 02:47:12.885825 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0625 02:47:12.904346 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" E0625 02:47:13.595352 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:14.595793 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8j4q9" "machine"="test-mhc-machine-njglz" "namespace"="test-mhc-n4s2v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vx6kq"} E0625 02:47:14.633764 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-njglz\" not found" "controller"="machine" "name"="test-mhc-machine-njglz" "namespace"="test-mhc-n4s2v" I0625 02:47:15.634355 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8j4q9" "machine"="test-mhc-machine-plhqm" "namespace"="test-mhc-n4s2v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4q9kd"} E0625 02:47:15.694884 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-plhqm\" not found" "controller"="machine" "name"="test-mhc-machine-plhqm" "namespace"="test-mhc-n4s2v" I0625 02:47:16.695389 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8j4q9" "machine"="test-mhc-machine-6ctb2" "namespace"="test-mhc-n4s2v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pnwld"} E0625 02:47:16.726701 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6ctb2\" not found" "controller"="machine" "name"="test-mhc-machine-6ctb2" "namespace"="test-mhc-n4s2v" I0625 02:47:17.733713 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" E0625 02:47:17.742917 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:47:17.743250 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" E0625 02:47:17.756292 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-n4s2v/test-cluster-8j4q9" node created: test-mhc-node-vqqkw E0625 02:47:17.809582 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vqqkw, got []" "node"="test-mhc-node-vqqkw" I0625 02:47:17.816198 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" inframachine created: test-mhc-machine-infra-8tsf7 machine created: test-mhc-machine-g5t8l I0625 02:47:17.842308 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:17.848876 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" E0625 02:47:18.743260 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:19.764696 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:19.770109 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:19.787945 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:19.797525 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:19.803980 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:19.808195 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" E0625 02:47:19.808523 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" node created: test-mhc-node-jxfm8 E0625 02:47:19.851314 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jxfm8, got []" "node"="test-mhc-node-jxfm8" I0625 02:47:19.856937 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" inframachine created: test-mhc-machine-infra-jvxqs I0625 02:47:19.879248 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" machine created: test-mhc-machine-9qrzw I0625 02:47:19.888558 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:19.894474 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" ... skipping 8 lines ... I0625 02:47:20.889719 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" Cleaning up nodes, machines and infra machines. I0625 02:47:20.895159 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" Cleaning up nodes, machines and infra machines. I0625 02:47:20.906616 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:20.908038 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:20.908475 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-jnlv5/" I0625 02:47:20.942293 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:20.942859 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-jnlv5/" I0625 02:47:20.943292 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-g5t8l/" I0625 02:47:20.958593 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" I0625 02:47:20.959130 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-g5t8l/" I0625 02:47:20.959581 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-jnlv5/" I0625 02:47:20.961476 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kt6q2" "namespace"="test-mhc-gjjqb" "count"=3 I0625 02:47:20.961551 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-kt6q2" "namespace"="test-mhc-gjjqb" "descendants"="Worker machines: test-mhc-machine-jnlv5,test-mhc-machine-g5t8l,test-mhc-machine-9qrzw" "indirect descendants count"=0 === RUN TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout === RUN TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away === RUN TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy I0625 02:47:20.965766 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" ... skipping 54 lines ... I0625 02:47:21.114448 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.122275 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.124829 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.126581 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.129045 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.130811 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" E0625 02:47:21.132300 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-g5t8l\" in namespace \"test-mhc-gjjqb\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-g5t8l" "namespace"="test-mhc-gjjqb" I0625 02:47:21.132489 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.134628 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.136490 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.138216 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.139919 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:21.141662 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" ... skipping 511 lines ... I0625 02:47:22.170215 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.173370 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.175009 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.176655 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.178360 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.180031 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" E0625 02:47:22.180788 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9qrzw\" not found" "controller"="machine" "name"="test-mhc-machine-9qrzw" "namespace"="test-mhc-gjjqb" I0625 02:47:22.181733 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.183340 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.184984 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.189380 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.191032 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:22.192737 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" ... skipping 518 lines ... I0625 02:47:23.220226 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.221918 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.223640 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.225366 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.227048 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.228758 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" E0625 02:47:23.229686 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jnlv5\" not found" "controller"="machine" "name"="test-mhc-machine-jnlv5" "namespace"="test-mhc-gjjqb" I0625 02:47:23.230451 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.232211 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.233958 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.235721 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.237485 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:23.239233 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" ... skipping 515 lines ... I0625 02:47:24.235323 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.236963 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.239469 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.240287 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.241170 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.242517 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.242732 10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/" I0625 02:47:24.242988 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kt6q2" "machine"="test-mhc-machine-g5t8l" "namespace"="test-mhc-gjjqb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jxfm8"} I0625 02:47:24.251573 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.251836 10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/" E0625 02:47:24.283274 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-g5t8l\" not found" "controller"="machine" "name"="test-mhc-machine-g5t8l" "namespace"="test-mhc-gjjqb" E0625 02:47:24.343071 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fnwkn, got []" "node"="test-mhc-node-fnwkn" E0625 02:47:24.343324 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fnwkn, got []" "node"="test-mhc-node-fnwkn" node created: test-mhc-node-fnwkn I0625 02:47:24.350382 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.364860 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.365922 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.375108 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.375465 10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn" I0625 02:47:24.390345 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.390822 10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn" Cleaning up nodes, machines and infra machines. I0625 02:47:24.402477 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.402939 10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn" I0625 02:47:24.404900 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.405203 10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn" I0625 02:47:24.407124 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.410596 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/" I0625 02:47:24.423449 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qjkqt" "namespace"="test-mhc-48fwl" "descendants"="Worker machines: test-mhc-machine-frlqr" "indirect descendants count"=1 I0625 02:47:24.423659 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" I0625 02:47:24.423944 10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/" I0625 02:47:24.427193 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" === RUN TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted I0625 02:47:24.427940 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qjkqt" "namespace"="test-mhc-48fwl" "descendants"="Worker machines: test-mhc-machine-frlqr" "indirect descendants count"=1 I0625 02:47:24.627337 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" "creating"=1 "need"=1 I0625 02:47:24.627384 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" I0625 02:47:24.648516 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-2h97j-t8lvk\"" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" I0625 02:47:24.696015 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:24.720973 10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I0625 02:47:24.838036 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:24.846416 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" E0625 02:47:25.283666 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:25.838300 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" E0625 02:47:25.979068 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-gjjqb/test-cluster-kt6q2" E0625 02:47:26.284103 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:47:26.839391 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:27.284632 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qjkqt" "machine"="test-mhc-machine-frlqr" "namespace"="test-mhc-48fwl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-fnwkn"} E0625 02:47:27.320281 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-frlqr\" not found" "controller"="machine" "name"="test-mhc-machine-frlqr" "namespace"="test-mhc-48fwl" I0625 02:47:27.840315 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:28.327513 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:28.328045 10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" I0625 02:47:28.331448 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:28.331847 10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" I0625 02:47:28.337646 10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" ... skipping 4 lines ... I0625 02:47:28.347683 10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" I0625 02:47:28.351967 10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:28.352006 10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:28.841252 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:29.351812 10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:29.351859 10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" E0625 02:47:29.436383 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-48fwl/test-cluster-qjkqt" I0625 02:47:30.000574 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:30.000933 10422 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-kjqr9/test-mhc-jclhx/mhc-ms-2h97j-t8lvk/" I0625 02:47:30.006607 10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" I0625 02:47:30.009785 10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:30.009818 10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:30.011545 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:30.011897 10422 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-kjqr9/test-mhc-jclhx/mhc-ms-2h97j-t8lvk/" I0625 02:47:30.016280 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" I0625 02:47:30.016344 10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" I0625 02:47:30.016570 10422 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-kjqr9/test-mhc-jclhx/mhc-ms-2h97j-t8lvk/" I0625 02:47:30.021652 10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:30.021678 10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:30.037351 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-l9vnb" "namespace"="test-mhc-kjqr9" "count"=1 I0625 02:47:30.037412 10422 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-l9vnb" "namespace"="test-mhc-kjqr9" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-2h97j" I0625 02:47:30.037862 10422 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" "machine"="mhc-ms-2h97j-t8lvk" I0625 02:47:30.040571 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" ... skipping 16 lines ... I0625 02:47:30.236122 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.237864 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.238581 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.240284 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.241179 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-l9vnb" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" "cause"="cluster is being deleted" "node"=null I0625 02:47:30.241576 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" E0625 02:47:30.265434 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-2h97j-t8lvk\" not found" "controller"="machine" "name"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" I0625 02:47:30.282934 10422 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-mb7wc" "target"="test-mhc-8n46k/test-mhc-2tqk4/test-mhc-machine-mb7wc/" I0625 02:47:30.291851 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" node created: test-mhc-node-gr2ch E0625 02:47:30.308646 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gr2ch, got []" "node"="test-mhc-node-gr2ch" E0625 02:47:30.308903 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gr2ch, got []" "node"="test-mhc-node-gr2ch" I0625 02:47:30.312967 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.325814 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.335346 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.337801 10422 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-mb7wc" "target"="test-mhc-8n46k/test-mhc-2tqk4/test-mhc-machine-mb7wc/test-mhc-node-gr2ch" I0625 02:47:30.349999 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" Cleaning up nodes, machines and infra machines. I0625 02:47:30.359476 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.361278 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.364481 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" I0625 02:47:30.367961 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mr826" "namespace"="test-mhc-8n46k" "descendants"="Worker machines: test-mhc-machine-mb7wc" "indirect descendants count"=1 ... skipping 511 lines ... I0625 02:47:31.285418 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.287089 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.290206 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.291802 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.293501 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.295020 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" E0625 02:47:31.296660 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mb7wc\" not found" "controller"="machine" "name"="test-mhc-machine-mb7wc" "namespace"="test-mhc-8n46k" I0625 02:47:31.296721 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.298249 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.299848 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.301516 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.303388 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:31.305214 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" ... skipping 585 lines ... I0625 02:47:32.287938 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.289596 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.291336 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.292894 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.294428 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.295994 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" E0625 02:47:32.296975 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" I0625 02:47:32.297517 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.299201 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.300713 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.302279 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.303876 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:32.305475 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" ... skipping 615 lines ... I0625 02:47:33.303955 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.305112 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.305788 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.307379 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.309142 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.309964 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" E0625 02:47:33.310140 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" I0625 02:47:33.312912 10422 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-kc9h6" "target"="test-mhc-sds2d/test-mhc-kb7ll/test-mhc-machine-kc9h6/" node created: test-mhc-node-nqrvp E0625 02:47:33.319820 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nqrvp, got []" "node"="test-mhc-node-nqrvp" E0625 02:47:33.319852 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nqrvp, got []" "node"="test-mhc-node-nqrvp" E0625 02:47:33.319864 10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nqrvp, got []" "node"="test-mhc-node-nqrvp" I0625 02:47:33.322673 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.326445 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.344789 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.348799 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.352423 10422 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-kc9h6" "target"="test-mhc-sds2d/test-mhc-kb7ll/test-mhc-machine-kc9h6/test-mhc-node-nqrvp" I0625 02:47:33.368147 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.371184 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.375308 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.395752 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" Cleaning up nodes, machines and infra machines. I0625 02:47:33.410065 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" I0625 02:47:33.416399 10422 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-kc9h6" "target"="test-mhc-sds2d/test-mhc-kb7ll/test-mhc-machine-kc9h6/" I0625 02:47:33.423541 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c25rk" "namespace"="test-mhc-sds2d" "descendants"="Worker machines: test-mhc-machine-kc9h6" "indirect descendants count"=1 I0625 02:47:33.433769 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c25rk" "namespace"="test-mhc-sds2d" "descendants"="Worker machines: test-mhc-machine-kc9h6" "indirect descendants count"=1 E0625 02:47:33.434649 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-kb7ll\" not found" "controller"="machinehealthcheck" "name"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" --- PASS: TestMachineHealthCheck_Reconcile (41.28s) --- 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.13s) --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (0.96s) --- 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 (0.33s) --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.06s) === RUN TestClusterToMachineHealthCheck === RUN TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster E0625 02:47:33.437866 10422 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 E0625 02:47:33.439361 10422 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 E0625 02:47:33.440985 10422 machinehealthcheck_controller.go:474] "msg"="expected a Node" "error"="incorrect type" "type"="handler.MapObject" === RUN TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node E0625 02:47:33.441199 10422 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 E0625 02:47:33.441580 10422 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 I0625 02:47:33.444490 10422 machinehealthcheck_controller.go:387] "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="" "target"="default/mhc/machine1/" I0625 02:47:33.444885 10422 machinehealthcheck_controller.go:387] "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="" "target"="default/mhc/machine2/" E0625 02:47:33.445921 10422 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 E0625 02:47:33.457665 10422 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 E0625 02:47:33.460507 10422 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 82 lines ... I0625 02:47:33.471959 10422 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•[0mI0625 02:47:33.473760 10422 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" I0625 02:47:33.474676 10422 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" I0625 02:47:33.475576 10422 machine_controller_phases.go:278] "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" I0625 02:47:33.475641 10422 machine_controller_noderef.go:45] "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" [32m•[0mI0625 02:47:33.476238 10422 machine_controller.go:327] "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" E0625 02:47:33.477792 10422 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•[0mE0625 02:47:33.600961 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-9jlqk\" not found" "controller"="cluster" "name"="test1-9jlqk" "namespace"="default" I0625 02:47:34.310744 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c25rk" "machine"="test-mhc-machine-kc9h6" "namespace"="test-mhc-sds2d" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nqrvp"} E0625 02:47:34.348521 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kc9h6\" not found" "controller"="machine" "name"="test-mhc-machine-kc9h6" "namespace"="test-mhc-sds2d" I0625 02:47:34.434886 10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" [32m•[0mI0625 02:47:34.734050 10422 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-ndgsx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" I0625 02:47:34.856260 10422 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-ndgsx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" E0625 02:47:34.860567 10422 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-ndgsx" "namespace"="default" E0625 02:47:35.872413 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" [32m•[0mE0625 02:47:36.882873 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-kjqr9/test-cluster-l9vnb" E0625 02:47:36.890942 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-8n46k/test-cluster-mr826" E0625 02:47:36.900690 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-rv48v\" not found" "controller"="cluster" "name"="test3-rv48v" "namespace"="default" E0625 02:47:37.901337 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" E0625 02:47:38.911005 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" [32m•[0mE0625 02:47:39.920296 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-sds2d/test-cluster-c25rk" E0625 02:47:39.923128 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-bgb7h: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default" E0625 02:47:40.923788 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" E0625 02:47:41.932612 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-bgb7h: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default" [32m•[0mE0625 02:47:42.537371 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2" E0625 02:47:42.933263 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" E0625 02:47:43.550434 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" E0625 02:47:43.933872 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-bgb7h: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default" E0625 02:47:44.942116 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" I0625 02:47:45.012360 10422 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-m4js5" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" E0625 02:47:45.025037 10422 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-m4js5" "namespace"="default" E0625 02:47:45.037981 10422 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-m4js5" "namespace"="default" E0625 02:47:45.942798 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-bgb7h: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default" I0625 02:47:46.051191 10422 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-m4js5" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)" I0625 02:47:46.051383 10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-m4js5" "namespace"="default" "noderef"="id-node-1" E0625 02:47:46.060896 10422 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-m4js5" "namespace"="default" E0625 02:47:46.947434 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" [32m•[0mI0625 02:47:47.058043 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-gxcpw" "namespace"="ms-test" "creating"=2 "need"=2 I0625 02:47:47.058104 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-gxcpw" "namespace"="ms-test" I0625 02:47:47.061282 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-kgkfh" "machine"="test6-m4js5" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"b51521bb-bc99-4712-a725-6675a5ce9130","apiVersion":"v1"} I0625 02:47:47.068564 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-gxcpw-dh68n\"" "machineset"="ms-gxcpw" "namespace"="ms-test" I0625 02:47:47.068666 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-gxcpw" "namespace"="ms-test" E0625 02:47:47.078816 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-m4js5\" in namespace \"default\": failed to retrieve external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-m4js5" "namespace"="default" I0625 02:47:47.081068 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-gxcpw-s9gkk\"" "machineset"="ms-gxcpw" "namespace"="ms-test" I0625 02:47:47.180488 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-gxcpw" "namespace"="ms-test" "creating"=1 "need"=2 I0625 02:47:47.180527 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-gxcpw" "namespace"="ms-test" I0625 02:47:47.192289 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-gxcpw-fhh7p\"" "machineset"="ms-gxcpw" "namespace"="ms-test" E0625 02:47:47.417133 10422 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-gxcpw-fhh7p-r6gjj for machine ms-test/ms-gxcpw-fhh7p: the cache is not started, can not read objects" "machineset"="ms-gxcpw" "namespace"="ms-test" E0625 02:47:47.541189 10422 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="ms-test/test-cluster" [32m•[0mI0625 02:47:47.578610 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2 I0625 02:47:47.578637 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" I0625 02:47:47.600679 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-b4v6b-6657c7fddb-pjzrw\"" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" I0625 02:47:47.600731 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" I0625 02:47:47.618010 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-b4v6b-6657c7fddb-x5p6h\"" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" I0625 02:47:47.670571 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2 ... skipping 4 lines ... I0625 02:47:47.781049 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3 I0625 02:47:47.781086 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" I0625 02:47:47.789065 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-6657c7fddb-9xlzg\"" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" I0625 02:47:47.895619 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1 I0625 02:47:47.895652 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" I0625 02:47:47.908941 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-cdfc6fd6c-xkqd2\"" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" E0625 02:47:47.947907 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test\" for Cluster default/test4-bgb7h: failed to retrieve external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default" E0625 02:47:48.006800 10422 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-b4v6b-cdfc6fd6c-xkqd2-m9bf8 for machine md-test/md-b4v6b-cdfc6fd6c-xkqd2: the cache is not started, can not read objects" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" I0625 02:47:48.024773 10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2 I0625 02:47:48.024808 10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "delete-policy"="Random" I0625 02:47:48.029873 10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "machine"="md-b4v6b-6657c7fddb-s4nwb" I0625 02:47:48.047586 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2 I0625 02:47:48.047642 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" I0625 02:47:48.056029 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-cdfc6fd6c-4d2x8\"" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" I0625 02:47:48.079275 10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-kgkfh" "machine"="test6-m4js5" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"b51521bb-bc99-4712-a725-6675a5ce9130","apiVersion":"v1"} E0625 02:47:48.079792 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-m4js5\" in namespace \"default\": failed to retrieve external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-m4js5" "namespace"="default" I0625 02:47:48.178956 10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1 I0625 02:47:48.178988 10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "delete-policy"="Random" I0625 02:47:48.183469 10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "machine"="md-b4v6b-6657c7fddb-5jqh6" I0625 02:47:48.289668 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3 I0625 02:47:48.289697 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" I0625 02:47:48.296783 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-cdfc6fd6c-m44wf\"" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" ... skipping 5 lines ... I0625 02:47:48.627944 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-74d45c49c5-r4nxf\"" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" I0625 02:47:48.936106 10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2 I0625 02:47:48.936231 10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random" I0625 02:47:48.939860 10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "machine"="md-b4v6b-cdfc6fd6c-4d2x8" I0625 02:47:48.948273 10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-kgkfh" "namespace"="default" "count"=1 I0625 02:47:48.948337 10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-kgkfh" "namespace"="default" "descendants"="Control plane machines: test6-m4js5" "indirect descendants count"=0 E0625 02:47:48.962645 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default" I0625 02:47:49.048614 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2 I0625 02:47:49.048668 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" I0625 02:47:49.056788 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-74d45c49c5-zhqkd\"" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" E0625 02:47:49.080107 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-gxcpw-s9gkk\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-gxcpw-s9gkk" "namespace"="ms-test" I0625 02:47:49.162018 10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1 I0625 02:47:49.162053 10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random" I0625 02:47:49.165238 10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "machine"="md-b4v6b-cdfc6fd6c-m44wf" I0625 02:47:49.271166 10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3 I0625 02:47:49.271204 10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" I0625 02:47:49.277919 10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-74d45c49c5-2hbjk\"" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" E0625 02:47:49.499997 10422 machinedeployment_controller.go:149] controllers/MachineDeployment "msg"="Failed to reconcile MachineDeployment" "error"="MachineDeployment.cluster.x-k8s.io \"md-b4v6b\" not found" "machinedeployment"="md-b4v6b" "namespace"="md-test" E0625 02:47:49.500254 10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="MachineDeployment.cluster.x-k8s.io \"md-b4v6b\" not found" "controller"="machinedeployment" "name"="md-b4v6b" "namespace"="md-test" [32m•[0m [1m[32mRan 16 of 16 Specs in 16.043 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m16 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestGinkgoSuite (16.04s) PASS Tearing down test suite E0625 02:47:49.505799 10422 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0625 02:47:49.505840 10422 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-887230872/tls.crt: no such file or directory" E0625 02:47:49.505860 10422 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0625 02:47:49.505880 10422 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-887230872/tls.crt: no such file or directory" I0625 02:47:49.505921 10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" I0625 02:47:49.505946 10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" I0625 02:47:49.506025 10422 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" I0625 02:47:49.506112 10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" I0625 02:47:49.506147 10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" I0625 02:47:49.506166 10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" I0625 02:47:49.506179 10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" E0625 02:47:49.531770 10422 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:34359/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1233&timeout=10s&timeoutSeconds=372&watch=true: dial tcp 127.0.0.1:34359: connect: connection refused E0625 02:47:49.533261 10422 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:34359/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1233&timeout=10s&timeoutSeconds=393&watch=true: dial tcp 127.0.0.1:34359: connect: connection refused ok sigs.k8s.io/cluster-api/controllers 73.229s === RUN TestGetResourceFound --- PASS: TestGetResourceFound (0.00s) === RUN TestGetResourceNotFound --- PASS: TestGetResourceNotFound (0.00s) === RUN TestCloneTemplateResourceNotFound ... skipping 256 lines ... I0625 02:46:48.953421 10837 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook" "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset" I0625 02:46:48.953442 10837 server.go:121] controller-runtime/webhook "msg"="registering webhook" "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset" I0625 02:46:48.953593 10837 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server" I0625 02:46:48.954415 10837 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate" I0625 02:46:48.954602 10837 server.go:199] controller-runtime/webhook "msg"="serving webhook server" "host"="" "port"=37379 I0625 02:46:48.954686 10837 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher" E0625 02:46:51.210568 10837 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="cluster-cache-test-bm82n/test-cluster" [32m•[0mE0625 02:46:51.650989 10837 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="the server could not find the requested resource" "cluster"="cluster-cache-test-tp2s4/test-cluster" [32m•[0mE0625 02:46:52.263363 10837 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:42831/?timeout=50ms: dial tcp 127.0.0.1:42831: connect: connection refused" "cluster"="cluster-cache-test-zr4jg/test-cluster" [32m•[0mI0625 02:46:52.499059 10837 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}} I0625 02:46:52.599362 10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" I0625 02:46:52.599416 10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1 I0625 02:46:52.635914 10837 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={} [32m•[0mI0625 02:46:53.158627 10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" I0625 02:46:53.172562 10837 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}}} I0625 02:46:53.272911 10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" I0625 02:46:53.272962 10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1 [32m•[0mE0625 02:46:53.456369 10837 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0625 02:46:53.456422 10837 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-978526235/tls.crt: no such file or directory" I0625 02:46:53.456512 10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" I0625 02:46:53.456574 10837 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" E0625 02:46:53.499448 10837 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:35901/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:35901: connect: connection refused [1m[32mRan 5 of 5 Specs in 15.364 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m5 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestGinkgoSuite (15.36s) PASS ok sigs.k8s.io/cluster-api/controllers/remote 15.558s ? 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 I0625 02:46:59.575551 11539 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 E0625 02:46:59.576783 11539 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 I0625 02:46:59.577417 11539 controller.go:136] "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" I0625 02:46:59.577586 11539 controller.go:136] "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" --- PASS: TestReconcilePaused (0.00s) === RUN TestReconcileClusterNoEndpoints ... skipping 94 lines ... I0625 02:47:10.255240 11539 remediation.go:248] "msg"="etcd cluster projected after remediation of m1-unhealthy-7lr6n" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-fglng (m2-healthy-fglng)","node-m3-healthy-8cgnp (m3-healthy-8cgnp)"] "targetQuorum"=2 "targetTotalMembers"=2 "targetUnhealthyMembers"=0 "unhealthyMembers"=[] I0625 02:47:10.259702 11539 remediation.go:154] "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-7lr6n" === RUN TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade) I0625 02:47:10.372305 11539 remediation.go:195] "msg"="etcd cluster before remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "currentMembers"=["node-m1-unhealthy-r8bxm","node-m2-healthy-5pxcj","node-m3-healthy-5dnhf","node-m4-healthy-75glm"] "currentTotalMembers"=4 I0625 02:47:10.372380 11539 remediation.go:248] "msg"="etcd cluster projected after remediation of m1-unhealthy-r8bxm" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-5pxcj (m2-healthy-5pxcj)","node-m3-healthy-5dnhf (m3-healthy-5dnhf)","node-m4-healthy-75glm (m4-healthy-75glm)"] "targetQuorum"=2 "targetTotalMembers"=3 "targetUnhealthyMembers"=0 "unhealthyMembers"=[] I0625 02:47:10.375180 11539 remediation.go:154] "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-r8bxm" --- FAIL: TestReconcileUnhealthyMachines (0.65s) --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_are_no_unhealthy_machines (0.00s) --- PASS: TestReconcileUnhealthyMachines/reconcileUnhealthyMachines_return_early_if_the_machine_to_be_remediated_is_marked_for_deletion (0.00s) --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_desired_replicas_<=_1 (0.03s) --- FAIL: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_number_of_machines_lower_than_desired (0.03s) remediation_test.go:841: Expected <string>: to equal <string>: KCP waiting for having at least 3 control plane machines before triggering remediation --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_a_deleting_machine (0.04s) ... skipping 86 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 I0625 02:47:13.092980 11539 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 I0625 02:47:13.093149 11539 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: [1m1656125207[0m Will run [1m1[0m of [1m1[0m specs E0625 02:47:13.119496 11539 controller.go:126] "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-mdx2uw\" not found" "kubeadmControlPlane"="kcp-foo-mdx2uw" "namespace"="test" [32m•[0m [1m[32mRan 1 of 1 Specs in 0.022 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 I0625 02:47:13.121122 11539 controller.go:246] "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-q6uum1" "kubeadmControlPlane"="kcp-foo-q6uum1" "namespace"="test" I0625 02:47:14.814894 11539 controller.go:331] "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-q6uum1" "kubeadmControlPlane"="kcp-foo-q6uum1" "namespace"="test" "needRollout"=["kcp-foo-q6uum1-xctfl"] I0625 02:47:14.815035 11539 scale.go:212] "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-q6uum1" "kubeadmControlPlane"="kcp-foo-q6uum1" "namespace"="test" "failures"="[machine kcp-foo-q6uum1-cshvx does not have APIServerPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have ControllerManagerPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have SchedulerPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have EtcdPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have EtcdMemberHealthy condition]" --- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.70s) FAIL I0625 02:47:14.815757 11539 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" FAIL sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers 27.177s I0625 02:46:57.996656 11502 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook" "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster" I0625 02:46:57.996761 11502 server.go:121] controller-runtime/webhook "msg"="registering webhook" "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster" I0625 02:46:57.996792 11502 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook" "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster" I0625 02:46:57.996807 11502 server.go:121] controller-runtime/webhook "msg"="registering webhook" "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster" I0625 02:46:57.996880 11502 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook" "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine" I0625 02:46:57.996895 11502 server.go:121] controller-runtime/webhook "msg"="registering webhook" "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine" ... skipping 51 lines ... ================================== Random Seed: [1m1656125207[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.000 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: [1m1656125207[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 E0625 02:46:59.884718 11502 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" E0625 02:47:08.209072 11502 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" E0625 02:47:17.195032 11502 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" E0625 02:47:28.325261 11502 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" E0625 02:47:44.798472 11502 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" E0625 02:47:57.807078 11502 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" E0625 02:48:15.454543 11502 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" E0625 02:48:36.377909 11502 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" E0625 02:49:07.394394 11502 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" E0625 02:49:52.551509 11502 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 E0625 02:49:52.557839 11502 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0625 02:49:52.557888 11502 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-428093671/tls.crt: no such file or directory" E0625 02:49:52.557904 11502 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E0625 02:49:52.557922 11502 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-428093671/tls.crt: no such file or directory" I0625 02:49:52.558009 11502 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" ok sigs.k8s.io/cluster-api/controlplane/kubeadm/internal 185.241s === RUN TestEtcdMembers_WithErrors --- PASS: TestEtcdMembers_WithErrors (0.00s) === RUN TestEtcdMembers_WithSuccess --- PASS: TestEtcdMembers_WithSuccess (0.00s) ... skipping 288 lines ... I0625 02:47:07.869808 11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1 I0625 02:47:07.870057 11862 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}} I0625 02:47:07.970452 11862 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}} I0625 02:47:08.070815 11862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" I0625 02:47:08.070889 11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1 I0625 02:47:08.139657 11862 clusterresourcesetbinding_controller.go:84] "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-hnb1x7"} E0625 02:47:08.209587 11862 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•[0mI0625 02:47:09.242138 11862 clusterresourcesetbinding_controller.go:84] "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-45tuc3"} E0625 02:47:09.269130 11862 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•[0m [90m------------------------------[0m [91m[1m• Failure [11.079 seconds][0m ClusterResourceSet Reconciler [90m/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40[0m [91m[1mShould reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It][0m ... skipping 8 lines ... [90m------------------------------[0m [1mSTEP[0m: Creating the Cluster [1mSTEP[0m: Creating the remote Cluster kubeconfig [1mSTEP[0m: Creating a Secret and a ConfigMap with ConfigMap in their data field [1mSTEP[0m: Verifying ClusterResourceSetBinding is created with cluster owner reference [1mSTEP[0m: Deleting the Kubeconfigsecret E0625 02:47:20.362712 11862 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" E0625 02:47:21.487400 11862 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•[0mE0625 02:47:22.522616 11862 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" E0625 02:47:23.535718 11862 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•[0mI0625 02:47:23.536661 11862 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" I0625 02:47:23.536679 11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" I0625 02:47:23.536659 11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" E0625 02:47:23.536946 11862 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed" E0625 02:47:23.537034 11862 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-959499860/tls.crt: no such file or directory" [91m[1mSummarizing 1 Failure:[0m [91m[1m[Fail] [0m[90mClusterResourceSet Reconciler [0m[91m[1m[It] Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [0m [37m/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:307[0m [1m[91mRan 5 of 5 Specs in 27.419 seconds[0m [1m[91mFAIL![0m -- [32m[1m4 Passed[0m | [91m[1m1 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- FAIL: TestAPIs (27.42s) FAIL FAIL sigs.k8s.io/cluster-api/exp/addons/controllers 27.498s ? sigs.k8s.io/cluster-api/exp/addons/controllers/predicates [no test files] === RUN TestMachinePoolDefault === RUN TestMachinePoolDefault/for_MachinePool === RUN TestMachinePoolDefault/for_MachinePool/validate-on-create === RUN TestMachinePoolDefault/for_MachinePool/validate-on-update === RUN TestMachinePoolDefault/for_MachinePool/validate-on-delete ... skipping 58 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 E0625 02:47:01.458505 12050 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 96 lines ... [32m•[0mI0625 02:47:12.367626 12050 machinepool_controller_noderef.go:90] "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes" [32m•[0m[32m•[0mI0625 02:47:12.369985 12050 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" I0625 02:47:12.404057 12050 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}} [1m[32mRan 9 of 9 Specs in 10.881 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m9 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (10.88s) PASS ok sigs.k8s.io/cluster-api/exp/controllers 11.132s ? 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 204 lines ... I0625 02:47:34.115121 15037 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher" I0625 02:47:34.115164 15037 server.go:199] controller-runtime/webhook "msg"="serving webhook server" "host"="" "port"=36193 [32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0mI0625 02:47:35.187539 15037 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" [1m[32mRan 14 of 14 Specs in 7.756 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m14 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestPatch (7.76s) === 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) ... skipping 105 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.034s FAIL make: *** [Makefile:116: test] Error 1