This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-11-29 03:37
Elapsed4m30s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I1129 03:39:03.022522    8427 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I1129 03:39:03.886795    8427 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" 
•I1129 03:39:03.897376    8427 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 12.576 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (12.58s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	48.875s
=== 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 1399 lines ...
I1129 03:38:50.560828   10488 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}}}
I1129 03:38:50.560911   10488 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I1129 03:38:50.560932   10488 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I1129 03:38:50.560952   10488 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I1129 03:38:50.560978   10488 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
=== RUN   TestClusterReconcilePhases
2022/11/29 03:38:50 http: TLS handshake error from 127.0.0.1:46846: EOF
=== 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
I1129 03:38:50.756682   10488 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"
I1129 03:38:50.759786   10488 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
... skipping 104 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I1129 03:38:50.800286   10488 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
I1129 03:38:50.801907   10488 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"
E1129 03:38:50.802211   10488 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
I1129 03:38:50.802665   10488 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I1129 03:38:51.050680   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E1129 03:38:51.053279   10488 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I1129 03:38:51.060372   10488 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-g2wzc" "namespace"="test-machine-watches-bqqq9" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I1129 03:38:51.060461   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I1129 03:38:51.173475   10488 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-g2wzc" "namespace"="test-machine-watches-bqqq9" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I1129 03:38:51.173575   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I1129 03:38:51.274542   10488 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-g2wzc" "namespace"="test-machine-watches-bqqq9" "noderef"="node-1"
E1129 03:38:51.284019   10488 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E1129 03:38:51.284089   10488 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I1129 03:38:51.309462   10488 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-g2wzc" "namespace"="test-machine-watches-bqqq9" "noderef"="node-1"
E1129 03:38:51.324850   10488 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-g2wzc\" in namespace \"test-machine-watches-bqqq9\", requeuing: requeue in 1s"  
E1129 03:38:51.339001   10488 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-g2wzc\" in namespace \"test-machine-watches-bqqq9\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-g2wzc\" in namespace \"test-machine-watches-bqqq9\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-g2wzc" "namespace"="test-machine-watches-bqqq9"
--- PASS: TestWatches (0.56s)
=== 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
I1129 03:38:51.458603   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-zkvnc" "namespace"="test-machine-watches-bqqq9" "count"=1
I1129 03:38:51.458679   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-zkvnc" "namespace"="test-machine-watches-bqqq9" "descendants"="Worker machines: machine-created-g2wzc" "indirect descendants count"=0
I1129 03:38:51.480817   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-zkvnc" "namespace"="test-machine-watches-bqqq9" "count"=1
I1129 03:38:51.480890   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-zkvnc" "namespace"="test-machine-watches-bqqq9" "descendants"="Worker machines: machine-created-g2wzc" "indirect descendants count"=0
I1129 03:38:52.345032   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zkvnc" "machine"="machine-created-g2wzc" "namespace"="test-machine-watches-bqqq9" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"4e5639e9-4d3d-49b4-87fa-8f4bcac525c9","apiVersion":"v1"}
E1129 03:38:52.399646   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-g2wzc\" not found" "controller"="machine" "name"="machine-created-g2wzc" "namespace"="test-machine-watches-bqqq9"
E1129 03:38:53.452353   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-jqglj\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-lmzr2\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-lmzr2: secrets \"machine-reconcile-lmzr2-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-jqglj" "namespace"="default"
I1129 03:38:54.452915   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lmzr2" "machine"="machine-created-jqglj" "namespace"="default" "cause"="noderef is nil" "node"=null
I1129 03:38:54.486666   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lmzr2" "machine"="machine-created-jqglj" "namespace"="default" "cause"="noderef is nil" "node"=null
I1129 03:38:54.505425   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lmzr2" "machine"="machine-created-jqglj" "namespace"="default" "cause"="noderef is nil" "node"=null
E1129 03:38:54.535914   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-jqglj\" not found" "controller"="machine" "name"="machine-created-jqglj" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.18s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.18s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.01s)
    --- 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
I1129 03:38:54.562862   10488 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E1129 03:38:54.566949   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-lmzr2\" not found" "controller"="cluster" "name"="machine-reconcile-lmzr2" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I1129 03:38:54.569308   10488 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I1129 03:38:54.585834   10488 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.03s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.01s)
... skipping 112 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I1129 03:38:54.784564   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rfh22" "namespace"="test-mhc-2tqwl" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I1129 03:38:54.836295   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E1129 03:38:54.837670   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-fcmbs\" not found"  "cluster"="test-mhc-2tqwl/test-cluster-fcmbs"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E1129 03:38:54.851111   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-rfh22\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-rfh22\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-rfh22" "namespace"="test-mhc-2tqwl"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I1129 03:38:55.851439   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nm2jd" "namespace"="test-mhc-wjzh7" 
I1129 03:38:55.851563   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rfh22" "namespace"="test-mhc-2tqwl" 
I1129 03:38:55.851605   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p4w7k" "namespace"="test-mhc-9m85m" 
I1129 03:38:55.851656   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p2cpf" "namespace"="test-mhc-r9fqp" 
I1129 03:38:55.870056   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1129 03:38:55.906967   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p2cpf" "namespace"="test-mhc-r9fqp" 
I1129 03:38:55.907673   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p2cpf" "namespace"="test-mhc-r9fqp" 
I1129 03:38:55.936399   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p2cpf" "namespace"="test-mhc-r9fqp" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E1129 03:38:55.943510   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-r9fqp/test-cluster-tsdx5"
E1129 03:38:55.946905   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-tsdx5\" not found" "controller"="cluster" "name"="test-cluster-tsdx5" "namespace"="test-mhc-r9fqp"
I1129 03:38:55.955557   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mgv6v" "namespace"="test-mhc-749kw" 
I1129 03:38:55.986414   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1129 03:38:56.009499   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mgv6v" "namespace"="test-mhc-749kw" 
E1129 03:38:56.061009   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-749kw/test-cluster-z6tf4"
I1129 03:38:56.065271   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mgv6v" "namespace"="test-mhc-749kw" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I1129 03:38:56.185253   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pkjpp" "namespace"="test-mhc-sjr2f" 
inframachine created: test-mhc-machine-infra-ppxgt
I1129 03:38:56.204189   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-vjm6k
I1129 03:38:56.304994   10488 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-sjr2f/test-mhc-pkjpp/test-mhc-machine-vjm6k/"
node created: test-mhc-node-j4qvj
E1129 03:38:56.316110   10488 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-j4qvj"
E1129 03:38:56.316366   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-j4qvj, got []"  "node"="test-mhc-node-j4qvj"
I1129 03:38:56.347374   10488 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f" "noderef"="test-mhc-node-j4qvj"
inframachine created: test-mhc-machine-infra-tdmqr
machine created: test-mhc-machine-65jzt
E1129 03:38:56.469087   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sgw9b, got []"  "node"="test-mhc-node-sgw9b"
E1129 03:38:56.469750   10488 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-sgw9b"
node created: test-mhc-node-sgw9b
I1129 03:38:56.471308   10488 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f" "noderef"="test-mhc-node-sgw9b"
E1129 03:38:56.478615   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sgw9b, got []"  "node"="test-mhc-node-sgw9b"
E1129 03:38:56.478665   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sgw9b, got []"  "node"="test-mhc-node-sgw9b"
E1129 03:38:56.479152   10488 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-sgw9b"
E1129 03:38:56.479206   10488 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-sgw9b"
I1129 03:38:56.526777   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pkjpp" "namespace"="test-mhc-sjr2f" 
I1129 03:38:56.585549   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pkjpp" "namespace"="test-mhc-sjr2f" 
Cleaning up nodes, machines and infra machines.
E1129 03:38:56.632719   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-sjr2f/test-cluster-5v8bz"
I1129 03:38:56.635462   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pkjpp" "namespace"="test-mhc-sjr2f" 
E1129 03:38:56.635560   10488 machinehealthcheck_controller.go:128] controllers/MachineHealthCheck "msg"="Failed to fetch Cluster for MachineHealthCheck" "error"="Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "cluster"="test-cluster-5v8bz" "machinehealthcheck"="test-mhc-pkjpp" "namespace"="test-mhc-sjr2f" 
E1129 03:38:56.635602   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machinehealthcheck" "name"="test-mhc-pkjpp" "namespace"="test-mhc-sjr2f"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-xmmhz
E1129 03:38:56.700593   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
machine created: test-mhc-machine-64h6n
E1129 03:38:56.964845   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-bqqq9/machine-reconcile-zkvnc"
I1129 03:38:57.635888   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pkjpp" "namespace"="test-mhc-sjr2f" 
I1129 03:38:57.636002   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.654346   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1129 03:38:57.678671   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.698129   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.699242   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
... skipping 2 lines ...
I1129 03:38:57.704449   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.706466   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.708308   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.708865   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.709982   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.711720   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
E1129 03:38:57.711876   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:38:57.712397   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.712819   10488 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-w9zk8/test-mhc-drh4n/test-mhc-machine-64h6n/"
E1129 03:38:57.717000   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-c6qn5, got []"  "node"="test-mhc-node-c6qn5"
node created: test-mhc-node-c6qn5
I1129 03:38:57.726720   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
inframachine created: test-mhc-machine-infra-bwbh2
machine created: test-mhc-machine-7sqng
I1129 03:38:57.752019   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:57.761287   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
... skipping 353 lines ...
I1129 03:38:58.698669   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.700856   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.703386   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.707775   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.709845   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.711920   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
E1129 03:38:58.713305   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:38:58.714123   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.716276   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.718427   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.720431   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.734838   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:58.736996   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
... skipping 270 lines ...
I1129 03:38:59.738588   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.739950   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.741235   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.742377   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.748350   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.749850   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
E1129 03:38:59.753784   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:38:59.755269   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.756632   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.758348   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.759706   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.761014   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:38:59.762456   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
... skipping 335 lines ...
I1129 03:39:00.761107   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.763309   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.765494   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.767367   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.769233   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.771413   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
E1129 03:39:00.772707   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:00.774950   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.775361   10488 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-w9zk8/test-mhc-drh4n/test-mhc-machine-7sqng/"
I1129 03:39:00.791504   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.791923   10488 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-w9zk8/test-mhc-drh4n/test-mhc-machine-7sqng/"
node created: test-mhc-node-6k946
E1129 03:39:00.859433   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6k946, got []"  "node"="test-mhc-node-6k946"
I1129 03:39:00.869326   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
inframachine created: test-mhc-machine-infra-sv2ph
I1129 03:39:00.896133   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:00.905667   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
machine created: test-mhc-machine-t6w9d
I1129 03:39:00.913638   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
... skipping 199 lines ...
I1129 03:39:01.774636   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.777178   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.780534   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.783085   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.788334   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.789558   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
E1129 03:39:01.791274   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:39:01.801042   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.807660   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.812401   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.831184   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.841403   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:01.844214   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
... skipping 242 lines ...
I1129 03:39:02.834962   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.838776   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.841398   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.843064   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.844733   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.846720   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
E1129 03:39:02.847302   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:02.849549   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.851462   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.853307   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.856320   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.860604   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:02.863390   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
... skipping 220 lines ...
I1129 03:39:03.844478   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.848247   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.852065   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.854601   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.857854   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.863770   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
E1129 03:39:03.866526   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:39:03.866878   10488 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-w9zk8/test-mhc-drh4n/test-mhc-machine-t6w9d/"
I1129 03:39:03.877718   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.878244   10488 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-w9zk8/test-mhc-drh4n/test-mhc-machine-t6w9d/"
E1129 03:39:03.948864   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nvpk4, got []"  "node"="test-mhc-node-nvpk4"
node created: test-mhc-node-nvpk4
Cleaning up nodes, machines and infra machines.
I1129 03:39:03.956221   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.956856   10488 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-w9zk8/test-mhc-drh4n/test-mhc-machine-t6w9d/test-mhc-node-nvpk4"
I1129 03:39:03.966879   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-drh4n" "namespace"="test-mhc-w9zk8" 
I1129 03:39:03.967421   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-w9zk8/test-mhc-drh4n/test-mhc-machine-t6w9d/"
Cleaning up nodes, machines and infra machines.
I1129 03:39:04.016174   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-r564b" "namespace"="test-mhc-w9zk8" "count"=2
I1129 03:39:04.016267   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-r564b" "namespace"="test-mhc-w9zk8" "descendants"="Worker machines: test-mhc-machine-t6w9d,test-mhc-machine-64h6n,test-mhc-machine-7sqng" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I1129 03:39:04.021376   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-r564b" "namespace"="test-mhc-w9zk8" "count"=2
I1129 03:39:04.021430   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-r564b" "namespace"="test-mhc-w9zk8" "descendants"="Worker machines: test-mhc-machine-64h6n,test-mhc-machine-7sqng,test-mhc-machine-t6w9d" "indirect descendants count"=1
... skipping 7 lines ...
I1129 03:39:04.327236   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:04.368253   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:04.449272   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:04.610313   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:04.871097   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-r564b" "machine"="test-mhc-machine-7sqng" "namespace"="test-mhc-w9zk8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-6k946"}
I1129 03:39:04.931403   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:04.956760   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7sqng\" not found" "controller"="machine" "name"="test-mhc-machine-7sqng" "namespace"="test-mhc-w9zk8"
I1129 03:39:05.572650   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:05.957957   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:06.853747   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:06.958536   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-r564b" "machine"="test-mhc-machine-t6w9d" "namespace"="test-mhc-w9zk8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nvpk4"}
E1129 03:39:07.010997   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-t6w9d\" not found" "controller"="machine" "name"="test-mhc-machine-t6w9d" "namespace"="test-mhc-w9zk8"
E1129 03:39:08.011516   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:39:09.012090   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-r564b" "machine"="test-mhc-machine-64h6n" "namespace"="test-mhc-w9zk8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-c6qn5"}
I1129 03:39:09.021301   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-r564b" "namespace"="test-mhc-w9zk8" "count"=1
I1129 03:39:09.021383   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-r564b" "namespace"="test-mhc-w9zk8" "descendants"="Worker machines: test-mhc-machine-64h6n" "indirect descendants count"=0
E1129 03:39:09.064951   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-64h6n\" not found" "controller"="machine" "name"="test-mhc-machine-64h6n" "namespace"="test-mhc-w9zk8"
I1129 03:39:09.414800   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.072679   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.076182   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:10.077700   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
node created: test-mhc-node-2dw9l
E1129 03:39:10.098009   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2dw9l, got []"  "node"="test-mhc-node-2dw9l"
I1129 03:39:10.098266   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:10.099775   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2dw9l, got []"  "node"="test-mhc-node-2dw9l"
I1129 03:39:10.105353   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
inframachine created: test-mhc-machine-infra-cnzwv
machine created: test-mhc-machine-hgwqk
I1129 03:39:10.123227   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.136189   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.137369   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.142190   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.183520   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.264907   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.426302   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:10.747669   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:11.078196   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:39:11.389049   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.094273   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.095235   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.109332   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.121697   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.129009   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.135015   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.138443   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:12.140296   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:12.161662   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
node created: test-mhc-node-mrqpk
E1129 03:39:12.232414   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mrqpk, got []"  "node"="test-mhc-node-mrqpk"
E1129 03:39:12.232622   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mrqpk, got []"  "node"="test-mhc-node-mrqpk"
I1129 03:39:12.239743   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
inframachine created: test-mhc-machine-infra-mvzhk
I1129 03:39:12.250078   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.255960   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
machine created: test-mhc-machine-gp7nx
I1129 03:39:12.266733   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:12.671027   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:13.140705   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
E1129 03:39:14.041812   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-w9zk8/test-cluster-r564b"
I1129 03:39:14.153254   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.170771   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.179861   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.209349   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.244983   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.252493   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.256603   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
E1129 03:39:14.258884   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
node created: test-mhc-node-jrqsm
E1129 03:39:14.266421   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jrqsm, got []"  "node"="test-mhc-node-jrqsm"
Cleaning up nodes, machines and infra machines.
I1129 03:39:14.277706   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.287612   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
Cleaning up nodes, machines and infra machines.
I1129 03:39:14.325025   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-k7f62" "namespace"="test-mhc-vzknl" "count"=2
I1129 03:39:14.325117   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k7f62" "namespace"="test-mhc-vzknl" "descendants"="Worker machines: test-mhc-machine-6mcgq,test-mhc-machine-hgwqk,test-mhc-machine-gp7nx" "indirect descendants count"=1
... skipping 3 lines ...
inframachine created: test-mhc-machine-infra-pvlq7
machine created: test-mhc-machine-zhrl5
I1129 03:39:14.515576   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:14.545657   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1129 03:39:14.585104   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fpdbg" "namespace"="test-mhc-vzknl" 
I1129 03:39:14.585194   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
E1129 03:39:15.259287   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:39:16.259828   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k7f62" "machine"="test-mhc-machine-6mcgq" "namespace"="test-mhc-vzknl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2dw9l"}
E1129 03:39:16.311055   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6mcgq\" not found" "controller"="machine" "name"="test-mhc-machine-6mcgq" "namespace"="test-mhc-vzknl"
I1129 03:39:17.311702   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k7f62" "machine"="test-mhc-machine-hgwqk" "namespace"="test-mhc-vzknl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mrqpk"}
E1129 03:39:17.375117   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-hgwqk\" not found" "controller"="machine" "name"="test-mhc-machine-hgwqk" "namespace"="test-mhc-vzknl"
I1129 03:39:18.375624   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k7f62" "machine"="test-mhc-machine-gp7nx" "namespace"="test-mhc-vzknl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jrqsm"}
E1129 03:39:18.417403   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gp7nx\" not found" "controller"="machine" "name"="test-mhc-machine-gp7nx" "namespace"="test-mhc-vzknl"
E1129 03:39:19.343295   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vzknl/test-cluster-k7f62"
I1129 03:39:19.436138   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
E1129 03:39:19.442336   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:19.442753   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
node created: test-mhc-node-svh75
E1129 03:39:19.512347   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-svh75, got []"  "node"="test-mhc-node-svh75"
I1129 03:39:19.524887   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
inframachine created: test-mhc-machine-infra-h44bf
machine created: test-mhc-machine-llx7t
I1129 03:39:19.541771   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:19.547930   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
E1129 03:39:20.442739   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:39:21.462533   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:21.473939   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:21.484691   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:21.493289   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:21.507111   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
E1129 03:39:21.514344   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:21.514452   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
E1129 03:39:21.565790   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cbxqs, got []"  "node"="test-mhc-node-cbxqs"
node created: test-mhc-node-cbxqs
I1129 03:39:21.574869   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
inframachine created: test-mhc-machine-infra-qxdxt
I1129 03:39:21.595422   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
machine created: test-mhc-machine-h4qkg
I1129 03:39:21.601406   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
... skipping 2 lines ...
I1129 03:39:22.549973   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.559377   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.571071   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.581459   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.598768   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.608710   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
E1129 03:39:22.608880   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
Cleaning up nodes, machines and infra machines.
I1129 03:39:22.707910   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
Cleaning up nodes, machines and infra machines.
I1129 03:39:22.715439   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.716003   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bn9hr/test-mhc-gt79s/test-mhc-machine-zhrl5/"
I1129 03:39:22.732423   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.732956   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bn9hr/test-mhc-gt79s/test-mhc-machine-zhrl5/"
I1129 03:39:22.733360   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bn9hr/test-mhc-gt79s/test-mhc-machine-llx7t/"
I1129 03:39:22.775207   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gt79s" "namespace"="test-mhc-bn9hr" 
I1129 03:39:22.776688   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bn9hr/test-mhc-gt79s/test-mhc-machine-zhrl5/"
I1129 03:39:22.778023   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bn9hr/test-mhc-gt79s/test-mhc-machine-llx7t/"
I1129 03:39:22.792906   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kcx28" "namespace"="test-mhc-bn9hr" "count"=2
I1129 03:39:22.793015   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-kcx28" "namespace"="test-mhc-bn9hr" "descendants"="Worker machines: test-mhc-machine-zhrl5,test-mhc-machine-llx7t,test-mhc-machine-h4qkg" "indirect descendants count"=1
I1129 03:39:22.800033   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kcx28" "namespace"="test-mhc-bn9hr" "count"=2
I1129 03:39:22.800517   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-kcx28" "namespace"="test-mhc-bn9hr" "descendants"="Worker machines: test-mhc-machine-zhrl5,test-mhc-machine-llx7t,test-mhc-machine-h4qkg" "indirect descendants count"=1
=== 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
... skipping 318 lines ...
I1129 03:39:23.652723   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.655933   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.657764   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.659590   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.661541   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.663382   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
E1129 03:39:23.663609   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zhrl5\" not found" "controller"="machine" "name"="test-mhc-machine-zhrl5" "namespace"="test-mhc-bn9hr"
I1129 03:39:23.665123   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.666862   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.668599   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.670404   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.672243   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:23.674025   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
... skipping 509 lines ...
I1129 03:39:24.718131   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.720868   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.723891   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.729057   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.733120   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.736165   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
E1129 03:39:24.737895   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-llx7t\" not found" "controller"="machine" "name"="test-mhc-machine-llx7t" "namespace"="test-mhc-bn9hr"
I1129 03:39:24.738669   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.740478   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.742337   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.744368   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.746461   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:24.748648   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
... skipping 482 lines ...
I1129 03:39:25.769828   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.775673   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.778079   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.780752   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.783948   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.786246   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
E1129 03:39:25.788102   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-h4qkg\" not found" "controller"="machine" "name"="test-mhc-machine-h4qkg" "namespace"="test-mhc-bn9hr"
I1129 03:39:25.792796   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.795015   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.796962   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.798900   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.800976   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:25.802983   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
... skipping 421 lines ...
I1129 03:39:26.787864   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.792578   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.794632   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.796407   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.797844   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.801445   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.803108   10488 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-dbmmb/test-mhc-jz4qw/test-mhc-machine-nq4rw/"
E1129 03:39:26.802687   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:26.814648   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.815196   10488 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-dbmmb/test-mhc-jz4qw/test-mhc-machine-nq4rw/"
E1129 03:39:26.896040   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lfnrl, got []"  "node"="test-mhc-node-lfnrl"
node created: test-mhc-node-lfnrl
E1129 03:39:26.896356   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lfnrl, got []"  "node"="test-mhc-node-lfnrl"
I1129 03:39:26.906155   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.923627   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.930108   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.930452   10488 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-dbmmb/test-mhc-jz4qw/test-mhc-machine-nq4rw/test-mhc-node-lfnrl"
I1129 03:39:26.951365   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.951766   10488 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-dbmmb/test-mhc-jz4qw/test-mhc-machine-nq4rw/test-mhc-node-lfnrl"
I1129 03:39:26.956708   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.957118   10488 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-dbmmb/test-mhc-jz4qw/test-mhc-machine-nq4rw/test-mhc-node-lfnrl"
Cleaning up nodes, machines and infra machines.
I1129 03:39:26.965481   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.965885   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dbmmb/test-mhc-jz4qw/test-mhc-machine-nq4rw/"
I1129 03:39:26.983181   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
I1129 03:39:26.983501   10488 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dbmmb/test-mhc-jz4qw/test-mhc-machine-nq4rw/"
I1129 03:39:26.993999   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-b6wqq" "namespace"="test-mhc-dbmmb" "descendants"="Worker machines: test-mhc-machine-nq4rw" "indirect descendants count"=1
I1129 03:39:26.998620   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-b6wqq" "namespace"="test-mhc-dbmmb" "descendants"="Worker machines: test-mhc-machine-nq4rw" "indirect descendants count"=1
I1129 03:39:27.029382   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jz4qw" "namespace"="test-mhc-dbmmb" 
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I1129 03:39:27.132931   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" "creating"=1 "need"=1
I1129 03:39:27.132990   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:27.154088   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-mfhrw-b24vg\"" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:27.210829   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:27.231793   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1129 03:39:27.260198   10488 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:27.358558   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:27.367917   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
E1129 03:39:27.806580   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
E1129 03:39:27.813901   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-bn9hr/test-cluster-kcx28"
I1129 03:39:28.358799   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:28.807104   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-b6wqq" "machine"="test-mhc-machine-nq4rw" "namespace"="test-mhc-dbmmb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-lfnrl"}
E1129 03:39:28.854258   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nq4rw\" not found" "controller"="machine" "name"="test-mhc-machine-nq4rw" "namespace"="test-mhc-dbmmb"
I1129 03:39:29.359761   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.864996   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.865627   10488 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.875695   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.876483   10488 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.885584   10488 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" 
... skipping 2 lines ...
I1129 03:39:29.911647   10488 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.921139   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.922001   10488 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.937174   10488 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" 
I1129 03:39:29.937227   10488 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.360843   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.361295   10488 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-p8cnp/test-mhc-nqg94/mhc-ms-mfhrw-b24vg/"
I1129 03:39:30.370902   10488 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.376504   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.376883   10488 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-p8cnp/test-mhc-nqg94/mhc-ms-mfhrw-b24vg/"
I1129 03:39:30.377209   10488 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.377277   10488 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.387851   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.387987   10488 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.388184   10488 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-p8cnp/test-mhc-nqg94/mhc-ms-mfhrw-b24vg/"
I1129 03:39:30.397463   10488 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.397513   10488 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.477532   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2qdbb" "namespace"="test-mhc-p8cnp" "count"=1
I1129 03:39:30.477590   10488 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-2qdbb" "namespace"="test-mhc-p8cnp" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-mfhrw"
I1129 03:39:30.477955   10488 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" "machine"="mhc-ms-mfhrw-b24vg"
I1129 03:39:30.482721   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nqg94" "namespace"="test-mhc-p8cnp" 
I1129 03:39:30.485023   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2qdbb" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" "cause"="cluster is being deleted" "node"=null
I1129 03:39:30.486766   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2qdbb" "namespace"="test-mhc-p8cnp" "descendants"="Machine sets: mhc-ms-mfhrw;Worker machines: mhc-ms-mfhrw-b24vg" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
I1129 03:39:30.493922   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2qdbb" "namespace"="test-mhc-p8cnp" "descendants"="Worker machines: mhc-ms-mfhrw-b24vg" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
E1129 03:39:30.497357   10488 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-mfhrw\" not found" "machineset"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp" 
E1129 03:39:30.497454   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-mfhrw\" not found" "controller"="machineset" "name"="mhc-ms-mfhrw" "namespace"="test-mhc-p8cnp"
I1129 03:39:30.561323   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
inframachine created: test-mhc-machine-infra-7kzsh
I1129 03:39:30.578354   10488 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-vs5pl
I1129 03:39:30.732951   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.734106   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
... skipping 16 lines ...
I1129 03:39:30.762700   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.764385   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.766170   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.767977   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.769813   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.770359   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2qdbb" "machine"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp" "cause"="cluster is being deleted" "node"=null
E1129 03:39:30.804201   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-28p6v, got []"  "node"="test-mhc-node-28p6v"
E1129 03:39:30.804201   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-28p6v, got []"  "node"="test-mhc-node-28p6v"
E1129 03:39:30.804210   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-28p6v, got []"  "node"="test-mhc-node-28p6v"
node created: test-mhc-node-28p6v
I1129 03:39:30.832930   10488 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-vs5pl" "target"="test-mhc-n8xfr/test-mhc-7mlvf/test-mhc-machine-vs5pl/"
E1129 03:39:30.850404   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-mfhrw-b24vg\" not found" "controller"="machine" "name"="mhc-ms-mfhrw-b24vg" "namespace"="test-mhc-p8cnp"
I1129 03:39:30.852019   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.874871   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.883989   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.888613   10488 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-vs5pl" "target"="test-mhc-n8xfr/test-mhc-7mlvf/test-mhc-machine-vs5pl/test-mhc-node-28p6v"
I1129 03:39:30.930095   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.938347   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
Cleaning up nodes, machines and infra machines.
I1129 03:39:30.950403   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.953718   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
I1129 03:39:30.958625   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7mlvf" "namespace"="test-mhc-n8xfr" 
... skipping 378 lines ...
I1129 03:39:31.924407   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.926148   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.932842   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.937089   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.939414   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.941207   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
E1129 03:39:31.941367   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vs5pl\" not found" "controller"="machine" "name"="test-mhc-machine-vs5pl" "namespace"="test-mhc-n8xfr"
I1129 03:39:31.943213   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.945013   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.946784   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.948655   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.950498   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:31.952399   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
... skipping 24 lines ...
I1129 03:39:31.998159   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.000715   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.002524   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.004333   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.006296   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.008248   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
E1129 03:39:32.011031   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-dbmmb/test-cluster-b6wqq"
I1129 03:39:32.011307   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.013049   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.014843   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.016535   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.018324   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.020091   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
... skipping 491 lines ...
I1129 03:39:32.945465   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.947149   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.949915   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.950627   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.952753   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:32.954875   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
E1129 03:39:32.955189   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
I1129 03:39:32.958779   10488 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-vvksh" "target"="test-mhc-m94w2/test-mhc-fl6pg/test-mhc-machine-vvksh/"
I1129 03:39:32.971035   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
E1129 03:39:33.051238   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2hwhz, got []"  "node"="test-mhc-node-2hwhz"
node created: test-mhc-node-2hwhz
E1129 03:39:33.051275   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2hwhz, got []"  "node"="test-mhc-node-2hwhz"
E1129 03:39:33.051403   10488 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2hwhz, got []"  "node"="test-mhc-node-2hwhz"
I1129 03:39:33.058461   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:33.079789   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:33.092388   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:33.095917   10488 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-vvksh" "target"="test-mhc-m94w2/test-mhc-fl6pg/test-mhc-machine-vvksh/test-mhc-node-2hwhz"
I1129 03:39:33.115814   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:33.126518   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:33.147262   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
Cleaning up nodes, machines and infra machines.
I1129 03:39:33.152406   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
I1129 03:39:33.156385   10488 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-vvksh" "target"="test-mhc-m94w2/test-mhc-fl6pg/test-mhc-machine-vvksh/"
I1129 03:39:33.166303   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rn5pv" "namespace"="test-mhc-m94w2" "descendants"="Worker machines: test-mhc-machine-vvksh" "indirect descendants count"=1
I1129 03:39:33.175381   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rn5pv" "namespace"="test-mhc-m94w2" "descendants"="Worker machines: test-mhc-machine-vvksh" "indirect descendants count"=1
E1129 03:39:33.180690   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-fl6pg\" not found" "controller"="machinehealthcheck" "name"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2"
--- PASS: TestMachineHealthCheck_Reconcile (38.52s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.14s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.13s)
... 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.49s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.20s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E1129 03:39:33.183763   10488 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
E1129 03:39:33.184888   10488 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
E1129 03:39:33.186083   10488 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E1129 03:39:33.186350   10488 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
E1129 03:39:33.186743   10488 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
I1129 03:39:33.189199   10488 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I1129 03:39:33.189750   10488 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E1129 03:39:33.191522   10488 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
E1129 03:39:33.199121   10488 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
E1129 03:39:33.200445   10488 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 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1669693116
Will run 16 of 16 specs

•E1129 03:39:33.334175   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-2r5st\" not found" "controller"="cluster" "name"="test1-2r5st" "namespace"="default"
E1129 03:39:33.955642   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
I1129 03:39:34.180974   10488 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fl6pg" "namespace"="test-mhc-m94w2" 
•I1129 03:39:34.460708   10488 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-44xhm" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I1129 03:39:34.575969   10488 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-44xhm" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E1129 03:39:34.580309   10488 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-44xhm" "namespace"="default"
I1129 03:39:34.956126   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rn5pv" "machine"="test-mhc-machine-vvksh" "namespace"="test-mhc-m94w2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2hwhz"}
E1129 03:39:34.990547   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vvksh\" not found" "controller"="machine" "name"="test-mhc-machine-vvksh" "namespace"="test-mhc-m94w2"
E1129 03:39:35.594736   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
•E1129 03:39:36.605499   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-p8cnp/test-cluster-2qdbb"
E1129 03:39:36.615991   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-nfxc7\" not found" "controller"="cluster" "name"="test3-nfxc7" "namespace"="default"
E1129 03:39:37.616785   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
E1129 03:39:38.637528   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
E1129 03:39:38.637614   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-n8xfr/test-cluster-cncvv"
•E1129 03:39:39.649732   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-m94w2/test-cluster-rn5pv"
E1129 03:39:39.653492   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
E1129 03:39:40.654280   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
E1129 03:39:41.665629   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
•E1129 03:39:42.666401   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
E1129 03:39:43.195612   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-vjm6k\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-vjm6k" "namespace"="test-mhc-sjr2f"
E1129 03:39:43.667179   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
E1129 03:39:44.196075   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5v8bz\" for machine \"test-mhc-machine-65jzt\" in namespace \"test-mhc-sjr2f\": Cluster.cluster.x-k8s.io \"test-cluster-5v8bz\" not found" "controller"="machine" "name"="test-mhc-machine-65jzt" "namespace"="test-mhc-sjr2f"
E1129 03:39:44.676522   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
I1129 03:39:45.219547   10488 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-4jwfc" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I1129 03:39:45.330601   10488 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-4jwfc" "namespace"="default" "noderef"="id-node-1"
E1129 03:39:45.350887   10488 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-4jwfc" "namespace"="default"
E1129 03:39:45.677368   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
I1129 03:39:46.366181   10488 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-4jwfc" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E1129 03:39:46.366909   10488 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-4jwfc" "namespace"="default"
E1129 03:39:46.682301   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"

------------------------------
• [SLOW TEST:5.034 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 12 lines ...
I1129 03:39:47.004933   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I1129 03:39:47.004988   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" 
I1129 03:39:47.013935   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-qq9mv-6657c7fddb-dnjqg\"" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" 
I1129 03:39:47.112616   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I1129 03:39:47.112650   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" 
I1129 03:39:47.122287   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-qq9mv-cdfc6fd6c-hcbm8\"" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" 
E1129 03:39:47.336575   10488 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-qq9mv-cdfc6fd6c-hcbm8-k2lvc for machine md-test/md-qq9mv-cdfc6fd6c-hcbm8: the cache is not started, can not read objects" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" 
I1129 03:39:47.362187   10488 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I1129 03:39:47.362225   10488 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I1129 03:39:47.367193   10488 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "machine"="md-qq9mv-6657c7fddb-q9lm5"
I1129 03:39:47.367256   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jccmd" "machine"="test6-4jwfc" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"13d22bf0-c2dd-46fe-8da4-6bacddd8043f","apiVersion":"v1"}
I1129 03:39:47.385732   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I1129 03:39:47.385778   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" 
E1129 03:39:47.387899   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-4jwfc\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-4jwfc" "namespace"="default"
I1129 03:39:47.396849   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-qq9mv-cdfc6fd6c-jk8pt\"" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" 
I1129 03:39:47.571452   10488 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I1129 03:39:47.571489   10488 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I1129 03:39:47.575540   10488 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "machine"="md-qq9mv-6657c7fddb-lffp2"
I1129 03:39:47.597805   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I1129 03:39:47.597844   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" 
I1129 03:39:47.607002   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-qq9mv-cdfc6fd6c-4vpc8\"" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" 
E1129 03:39:47.683150   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
I1129 03:39:47.744879   10488 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I1129 03:39:47.744922   10488 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I1129 03:39:47.749340   10488 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-qq9mv-6657c7fddb" "namespace"="md-test" "machine"="md-qq9mv-6657c7fddb-dnjqg"
I1129 03:39:47.854245   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-qq9mv-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I1129 03:39:47.854295   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-qq9mv-74d45c49c5" "namespace"="md-test" 
I1129 03:39:47.865601   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-qq9mv-74d45c49c5-j5mbq\"" "machineset"="md-qq9mv-74d45c49c5" "namespace"="md-test" 
... skipping 7 lines ...
I1129 03:39:48.219916   10488 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I1129 03:39:48.224105   10488 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-qq9mv-cdfc6fd6c" "namespace"="md-test" "machine"="md-qq9mv-cdfc6fd6c-4vpc8"
I1129 03:39:48.332434   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-qq9mv-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I1129 03:39:48.332472   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-qq9mv-74d45c49c5" "namespace"="md-test" 
I1129 03:39:48.341156   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-qq9mv-74d45c49c5-jzdlk\"" "machineset"="md-qq9mv-74d45c49c5" "namespace"="md-test" 
I1129 03:39:48.409334   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jccmd" "machine"="test6-4jwfc" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"13d22bf0-c2dd-46fe-8da4-6bacddd8043f","apiVersion":"v1"}
E1129 03:39:48.409952   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-4jwfc\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-4jwfc" "namespace"="default"
E1129 03:39:48.462096   10488 machinedeployment_controller.go:149] controllers/MachineDeployment "msg"="Failed to reconcile MachineDeployment" "error"="MachineDeployment.cluster.x-k8s.io \"md-qq9mv\" not found" "machinedeployment"="md-qq9mv" "namespace"="md-test" 
E1129 03:39:48.462522   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="MachineDeployment.cluster.x-k8s.io \"md-qq9mv\" not found" "controller"="machinedeployment" "name"="md-qq9mv" "namespace"="md-test"
E1129 03:39:48.463337   10488 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
•E1129 03:39:48.476113   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-74d45c49c5" "namespace"="md-test"
I1129 03:39:48.683704   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-jccmd" "namespace"="default" "count"=1
I1129 03:39:48.683781   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-jccmd" "namespace"="default" "descendants"="Control plane machines: test6-4jwfc" "indirect descendants count"=0
E1129 03:39:48.688136   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
E1129 03:39:49.410470   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-cdfc6fd6c-jk8pt\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-cdfc6fd6c-jk8pt" "namespace"="md-test"
E1129 03:39:49.476583   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-cdfc6fd6c" "namespace"="md-test"
E1129 03:39:49.688852   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
E1129 03:39:50.410931   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-74d45c49c5-j5mbq\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-74d45c49c5-j5mbq" "namespace"="md-test"
E1129 03:39:50.477081   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-74d45c49c5" "namespace"="md-test"
I1129 03:39:50.698794   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-jccmd" "namespace"="default" "count"=1
I1129 03:39:50.698843   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-jccmd" "namespace"="default" "descendants"="Control plane machines: test6-4jwfc" "indirect descendants count"=0
E1129 03:39:50.699256   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
E1129 03:39:51.411461   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-74d45c49c5-b8zzx\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-74d45c49c5-b8zzx" "namespace"="md-test"
I1129 03:39:51.497589   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-mnx7p" "namespace"="ms-test" "creating"=2 "need"=2
I1129 03:39:51.497633   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-mnx7p" "namespace"="ms-test" 
I1129 03:39:51.509985   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-mnx7p-lm6mc\"" "machineset"="ms-mnx7p" "namespace"="ms-test" 
I1129 03:39:51.510043   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-mnx7p" "namespace"="ms-test" 
I1129 03:39:51.527740   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-mnx7p-m8mgj\"" "machineset"="ms-mnx7p" "namespace"="ms-test" 
E1129 03:39:51.534024   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-cdfc6fd6c" "namespace"="md-test"
E1129 03:39:51.699924   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
E1129 03:39:52.412041   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-74d45c49c5-jzdlk\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-74d45c49c5-jzdlk" "namespace"="md-test"
E1129 03:39:52.534404   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-74d45c49c5" "namespace"="md-test"
E1129 03:39:52.700992   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
E1129 03:39:53.412470   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-6657c7fddb-j8x62\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-6657c7fddb-j8x62" "namespace"="md-test"
I1129 03:39:53.541590   10488 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-mnx7p" "namespace"="ms-test" "creating"=1 "need"=2
I1129 03:39:53.541643   10488 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-mnx7p" "namespace"="ms-test" 
I1129 03:39:53.554186   10488 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-mnx7p-pzww2\"" "machineset"="ms-mnx7p" "namespace"="ms-test" 
E1129 03:39:53.659288   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-cdfc6fd6c" "namespace"="md-test"
E1129 03:39:53.701604   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
E1129 03:39:54.413012   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-6657c7fddb-g95r2\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-6657c7fddb-g95r2" "namespace"="md-test"
E1129 03:39:54.659714   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-74d45c49c5" "namespace"="md-test"
I1129 03:39:54.702158   10488 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-jccmd" "namespace"="default" "count"=1
I1129 03:39:54.702238   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-jccmd" "namespace"="default" "descendants"="Control plane machines: test6-4jwfc" "indirect descendants count"=0
E1129 03:39:54.702651   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-44xhm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-44xhm" "namespace"="default"
I1129 03:39:55.413720   10488 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jccmd" "machine"="test6-4jwfc" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"13d22bf0-c2dd-46fe-8da4-6bacddd8043f","apiVersion":"v1"}
E1129 03:39:55.414497   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-4jwfc\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-4jwfc" "namespace"="default"
E1129 03:39:55.675671   10488 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-mnx7p-m8mgj-xm7z7 for machine ms-test/ms-mnx7p-m8mgj: the cache is not started, can not read objects" "machineset"="ms-mnx7p" "namespace"="ms-test" 
E1129 03:39:55.675720   10488 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-mnx7p-pzww2-488c2 for machine ms-test/ms-mnx7p-pzww2: the cache is not started, can not read objects" "machineset"="ms-mnx7p" "namespace"="ms-test" 
E1129 03:39:55.680476   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-cdfc6fd6c" "namespace"="md-test"
E1129 03:39:55.703380   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pbrmj: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pbrmj" "namespace"="default"
E1129 03:39:56.414920   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-cdfc6fd6c-jk8pt\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-cdfc6fd6c-jk8pt" "namespace"="md-test"
E1129 03:39:56.680917   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-74d45c49c5" "namespace"="md-test"
E1129 03:39:57.415385   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-qq9mv-74d45c49c5-j5mbq\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-qq9mv-74d45c49c5-j5mbq" "namespace"="md-test"
E1129 03:39:57.691739   10488 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-qq9mv-cdfc6fd6c" "namespace"="md-test"
I1129 03:39:57.757930   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-mnx7p-pzww2,ms-mnx7p-m8mgj" "indirect descendants count"=2
I1129 03:39:57.764155   10488 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-mnx7p-pzww2,ms-mnx7p-m8mgj" "indirect descendants count"=2

------------------------------
• [SLOW TEST:9.299 seconds]
MachineSet Reconciler
... skipping 23 lines ...
I1129 03:39:57.777939   10488 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"
•I1129 03:39:57.779290   10488 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"
I1129 03:39:57.779906   10488 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"
I1129 03:39:57.780482   10488 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I1129 03:39:57.780508   10488 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I1129 03:39:57.780971   10488 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E1129 03:39:57.782161   10488 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" 
•

Ran 16 of 16 Specs in 24.582 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (24.58s)
PASS
Tearing down test suite
I1129 03:39:57.783660   10488 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I1129 03:39:57.783736   10488 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I1129 03:39:57.783789   10488 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I1129 03:39:57.783795   10488 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I1129 03:39:57.783813   10488 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I1129 03:39:57.783834   10488 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I1129 03:39:57.783855   10488 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E1129 03:39:57.814874   10488 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:33933/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1181&timeout=10s&timeoutSeconds=372&watch=true: dial tcp 127.0.0.1:33933: connect: connection refused
E1129 03:39:57.814874   10488 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:33933/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1181&timeout=10s&timeoutSeconds=393&watch=true: dial tcp 127.0.0.1:33933: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	81.221s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
I1129 03:38:50.696397   10941 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I1129 03:38:51.242042   10941 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I1129 03:38:51.256329   10941 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}}}
I1129 03:38:51.356694   10941 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I1129 03:38:51.356754   10941 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I1129 03:38:51.529682   10941 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E1129 03:38:53.580149   10941 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-q4gcg/test-cluster"
•E1129 03:38:54.092891   10941 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-94w9n/test-cluster"
•E1129 03:38:54.670098   10941 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:43321/?timeout=50ms: dial tcp 127.0.0.1:43321: connect: connection refused"  "cluster"="cluster-cache-test-djw8q/test-cluster"
•I1129 03:38:54.881114   10941 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1129 03:38:54.935545   10941 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:38945/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:38945: connect: connection refused


Ran 5 of 5 Specs in 16.356 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.36s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.561s
?   	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
I1129 03:39:02.384169   11589 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
E1129 03:39:02.385613   11589 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
I1129 03:39:02.386319   11589 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I1129 03:39:02.386480   11589 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 ...
I1129 03:39:13.540287   11589 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-xbh5q" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-6d29m (m2-healthy-6d29m)","node-m3-healthy-hgxcc (m3-healthy-hgxcc)"] "targetQuorum"=2 "targetTotalMembers"=2 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I1129 03:39:13.543749   11589 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-xbh5q"
=== RUN   TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade)
I1129 03:39:13.795236   11589 remediation.go:195]  "msg"="etcd cluster before remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "currentMembers"=["node-m1-unhealthy-rm8gs","node-m2-healthy-4lrt6","node-m3-healthy-cdm9p","node-m4-healthy-pmjqd"] "currentTotalMembers"=4
I1129 03:39:13.795322   11589 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-rm8gs" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-4lrt6 (m2-healthy-4lrt6)","node-m3-healthy-cdm9p (m3-healthy-cdm9p)","node-m4-healthy-pmjqd (m4-healthy-pmjqd)"] "targetQuorum"=2 "targetTotalMembers"=3 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I1129 03:39:13.799224   11589 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-rm8gs"
--- FAIL: TestReconcileUnhealthyMachines (1.08s)
    --- 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.06s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_number_of_machines_lower_than_desired (0.05s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_a_deleting_machine (0.05s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_at_least_one_additional_unhealthy_etcd_member_on_a_3_machine_CP (0.07s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_at_least_two_additional_unhealthy_etcd_member_on_a_5_machine_CP (0.17s)
    --- FAIL: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_2_CP_(during_1_CP_rolling_upgrade) (0.19s)
        remediation_test.go:839: 
            Expected
                <string>: WaitingForRemediation
            to equal
                <string>: RemediationInProgress
    --- PASS: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_3_CP (0.23s)
... skipping 82 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
I1129 03:39:16.689434   11589 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
I1129 03:39:16.689578   11589 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: 1669693128
Will run 1 of 1 specs

E1129 03:39:16.722584   11589 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-59n8ae\" not found" "kubeadmControlPlane"="kcp-foo-59n8ae" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.029 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.03s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I1129 03:39:16.723968   11589 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-m6239d" "kubeadmControlPlane"="kcp-foo-m6239d" "namespace"="test" 
I1129 03:39:18.763217   11589 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-m6239d" "kubeadmControlPlane"="kcp-foo-m6239d" "namespace"="test" "needRollout"=["kcp-foo-m6239d-xp64t"]
I1129 03:39:18.763385   11589 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-m6239d" "kubeadmControlPlane"="kcp-foo-m6239d" "namespace"="test" "failures"="[machine kcp-foo-m6239d-xg44v does not have APIServerPodHealthy condition, machine kcp-foo-m6239d-xg44v does not have ControllerManagerPodHealthy condition, machine kcp-foo-m6239d-xg44v does not have SchedulerPodHealthy condition, machine kcp-foo-m6239d-xg44v does not have EtcdPodHealthy condition, machine kcp-foo-m6239d-xg44v does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (2.04s)
FAIL
I1129 03:39:18.764219   11589 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1129 03:39:18.764233   11589 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1129 03:39:18.764285   11589 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-571180376/tls.crt: no such file or directory"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	30.181s
I1129 03:39:00.802742   11515 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"
I1129 03:39:00.802957   11515 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I1129 03:39:00.803031   11515 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"
I1129 03:39:00.803098   11515 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I1129 03:39:00.803216   11515 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"
I1129 03:39:00.803280   11515 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1669693127
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1669693127
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- 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
E1129 03:39:03.698914   11515 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"  
E1129 03:39:12.025990   11515 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"  
E1129 03:39:21.012015   11515 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"  
E1129 03:39:32.142301   11515 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"  
E1129 03:39:48.615474   11515 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"  
E1129 03:40:01.624101   11515 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"  
E1129 03:40:19.271468   11515 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"  
E1129 03:40:40.194888   11515 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"  
E1129 03:41:11.211501   11515 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"  
E1129 03:41:56.368757   11515 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
E1129 03:41:56.379319   11515 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1129 03:41:56.379374   11515 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-080449626/tls.crt: no such file or directory"  
E1129 03:41:56.379395   11515 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1129 03:41:56.379417   11515 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-080449626/tls.crt: no such file or directory"  
I1129 03:41:56.380131   11515 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.966s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I1129 03:39:11.387009   11870 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I1129 03:39:11.487156   11870 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I1129 03:39:11.587525   11870 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I1129 03:39:11.587598   11870 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I1129 03:39:11.588002   11870 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I1129 03:39:11.681619   11870 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-d90wsh"} 
•E1129 03:39:11.746125   11870 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"
I1129 03:39:12.805082   11870 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-wc85pm"} 
•E1129 03:39:12.848770   11870 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"
E1129 03:39:13.916081   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E1129 03:39:14.958427   11870 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"
•E1129 03:39:16.135565   11870 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"
•E1129 03:39:17.191870   11870 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"
E1129 03:39:18.214395   11870 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"
•I1129 03:39:18.217855   11870 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I1129 03:39:18.217931   11870 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I1129 03:39:18.217948   11870 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 


Ran 5 of 5 Specs in 20.716 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.72s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	20.799s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.02s)
    --- 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
E1129 03:39:03.329984   12045 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 91 lines ...
•I1129 03:39:14.823093   12045 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I1129 03:39:14.863029   12045 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1129 03:39:14.880655   12045 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1129 03:39:14.882705   12045 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I1129 03:39:14.910742   12045 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1129 03:39:14.957370   12045 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E1129 03:39:14.960423   12045 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1129 03:39:14.960491   12045 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-797560809/tls.crt: no such file or directory"  
E1129 03:39:14.960524   12045 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1129 03:39:14.960598   12045 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-797560809/tls.crt: no such file or directory"  
I1129 03:39:14.961017   12045 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I1129 03:39:15.015075   12045 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}}}


Ran 9 of 9 Specs in 11.580 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.58s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.936s
?   	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 ...
I1129 03:39:37.629211   15026 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I1129 03:39:37.629282   15026 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39475
••••••••••••••I1129 03:39:38.832534   15026 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 14 of 14 Specs in 7.109 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (7.11s)
=== 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.036s
FAIL
make: *** [Makefile:116: test] Error 1