This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-06-24 14:45
Elapsed4m25s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I0624 14:47:02.725117    8374 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0624 14:47:02.725331    8374 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0624 14:47:02.727080    8374 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0624 14:47:02.727327    8374 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=37147
I0624 14:47:02.731468    8374 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0624 14:47:03.299548    8374 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" 
•E0624 14:47:03.318691    8374 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0624 14:47:03.318751    8374 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-504978572/tls.crt: no such file or directory"  
E0624 14:47:03.318771    8374 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0624 14:47:03.318831    8374 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-504978572/tls.crt: no such file or directory"  
I0624 14:47:03.318948    8374 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 14.010 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.01s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	43.832s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0624 14:46:52.948072   10465 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
I0624 14:46:52.948594   10465 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0624 14:46:52.948666   10465 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0624 14:46:52.948719   10465 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}}}
I0624 14:46:52.948764   10465 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0624 14:46:52.948802   10465 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
2022/06/24 14:46:53 http: TLS handshake error from 127.0.0.1:43856: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0624 14:46:53.046105   10465 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"
I0624 14:46:53.049681   10465 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0624 14:46:53.082131   10465 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
I0624 14:46:53.083732   10465 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"
E0624 14:46:53.083995   10465 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
I0624 14:46:53.084477   10465 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
I0624 14:46:53.435724   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0624 14:46:53.438629   10465 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0624 14:46:53.443672   10465 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wx9rz" "namespace"="test-machine-watches-96cjz" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0624 14:46:53.443864   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0624 14:46:53.553049   10465 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wx9rz" "namespace"="test-machine-watches-96cjz" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0624 14:46:53.553150   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0624 14:46:53.656748   10465 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-wx9rz" "namespace"="test-machine-watches-96cjz" "noderef"="node-1"
E0624 14:46:53.667015   10465 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0624 14:46:53.667074   10465 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0624 14:46:53.718402   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-wx9rz\" in namespace \"test-machine-watches-96cjz\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-wx9rz" "namespace"="test-machine-watches-96cjz"
E0624 14:46:54.723416   10465 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-wx9rz\" in namespace \"test-machine-watches-96cjz\", requeuing: requeue in 1s"  
E0624 14:46:54.731298   10465 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-wx9rz\" in namespace \"test-machine-watches-96cjz\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-wx9rz\" in namespace \"test-machine-watches-96cjz\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-wx9rz" "namespace"="test-machine-watches-96cjz"
--- PASS: TestWatches (1.67s)
=== 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
I0624 14:46:54.947572   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-hf54b" "namespace"="test-machine-watches-96cjz" "count"=1
I0624 14:46:54.947642   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-hf54b" "namespace"="test-machine-watches-96cjz" "descendants"="Worker machines: machine-created-wx9rz" "indirect descendants count"=0
I0624 14:46:54.966221   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-hf54b" "namespace"="test-machine-watches-96cjz" "count"=1
I0624 14:46:54.966277   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-hf54b" "namespace"="test-machine-watches-96cjz" "descendants"="Worker machines: machine-created-wx9rz" "indirect descendants count"=0
I0624 14:46:55.735692   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-hf54b" "machine"="machine-created-wx9rz" "namespace"="test-machine-watches-96cjz" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"0b8a457c-c6cf-4600-82c9-958d7b2942c8","apiVersion":"v1"}
E0624 14:46:55.781833   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-wx9rz\" not found" "controller"="machine" "name"="machine-created-wx9rz" "namespace"="test-machine-watches-96cjz"
E0624 14:46:56.831151   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-5p2qb\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-4c8ch\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-4c8ch: secrets \"machine-reconcile-4c8ch-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-5p2qb" "namespace"="default"
I0624 14:46:57.835726   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4c8ch" "machine"="machine-created-5p2qb" "namespace"="default" "cause"="noderef is nil" "node"=null
I0624 14:46:57.883735   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4c8ch" "machine"="machine-created-5p2qb" "namespace"="default" "cause"="noderef is nil" "node"=null
I0624 14:46:57.907204   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4c8ch" "machine"="machine-created-5p2qb" "namespace"="default" "cause"="noderef is nil" "node"=null
E0624 14:46:57.954040   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-5p2qb\" not found" "controller"="machine" "name"="machine-created-5p2qb" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.21s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.21s)
=== 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 15 lines ...
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0624 14:46:57.993333   10465 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0624 14:46:58.014094   10465 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"
E0624 14:46:58.017070   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-4c8ch\" not found" "controller"="cluster" "name"="machine-reconcile-4c8ch" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0624 14:46:58.018436   10465 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.06s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.02s)
    --- PASS: TestReconcileRequest/machine_should_be_updated (0.00s)
    --- PASS: TestReconcileRequest/machine_should_be_deleted (0.03s)
... skipping 110 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0624 14:46:58.215720   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-n44lx" "namespace"="test-mhc-q8m82" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0624 14:46:58.268168   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0624 14:46:58.268322   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-x89r2\" not found"  "cluster"="test-mhc-q8m82/test-cluster-x89r2"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E0624 14:46:58.375411   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-n44lx\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-n44lx\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-n44lx" "namespace"="test-mhc-q8m82"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0624 14:46:59.375682   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s45r6" "namespace"="test-mhc-8789f" 
I0624 14:46:59.375817   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-n44lx" "namespace"="test-mhc-q8m82" 
I0624 14:46:59.375857   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mmttd" "namespace"="test-mhc-mhsfv" 
I0624 14:46:59.375892   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nfc6k" "namespace"="test-mhc-n4shv" 
I0624 14:46:59.390640   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0624 14:46:59.415030   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nfc6k" "namespace"="test-mhc-n4shv" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0624 14:46:59.507920   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nfc6k" "namespace"="test-mhc-n4shv" 
E0624 14:46:59.532916   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-n4shv/test-cluster-826m5"
E0624 14:46:59.536693   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-826m5\" not found" "controller"="cluster" "name"="test-cluster-826m5" "namespace"="test-mhc-n4shv"
I0624 14:46:59.559266   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jkjkw" "namespace"="test-mhc-8p6nc" 
I0624 14:46:59.582356   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0624 14:46:59.606719   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jkjkw" "namespace"="test-mhc-8p6nc" 
E0624 14:46:59.664901   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8p6nc/test-cluster-wj5cr"
I0624 14:46:59.668839   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jkjkw" "namespace"="test-mhc-8p6nc" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0624 14:46:59.788121   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
inframachine created: test-mhc-machine-infra-zg486
I0624 14:46:59.808824   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-6vxvl
I0624 14:46:59.841445   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:46:59.841786   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-6vxvl/"
I0624 14:46:59.862427   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:46:59.862822   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-6vxvl/"
E0624 14:46:59.916005   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qr8ns, got []"  "node"="test-mhc-node-qr8ns"
E0624 14:46:59.916266   10465 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-qr8ns"
node created: test-mhc-node-qr8ns
I0624 14:46:59.924568   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
inframachine created: test-mhc-machine-infra-fmx6z
machine created: test-mhc-machine-456wl
I0624 14:46:59.962627   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:46:59.970265   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
... skipping 28 lines ...
I0624 14:47:00.062595   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.064076   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.066429   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.068740   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.070788   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.073267   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.073738   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.086010   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.087538   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.090233   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.090945   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.094201   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.094611   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.097664   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.098034   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.115445   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.115893   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.131715   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.132446   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.144109   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.144804   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
node created: test-mhc-node-6mv7k
E0624 14:47:00.160104   10465 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6mv7k"
E0624 14:47:00.160156   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6mv7k, got []"  "node"="test-mhc-node-6mv7k"
I0624 14:47:00.165604   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.166114   10465 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-2f55v/test-mhc-vwksw/test-mhc-machine-456wl/"
I0624 14:47:00.171494   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.173404   10465 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v" "noderef"="test-mhc-node-6mv7k"
I0624 14:47:00.202179   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.207906   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
Cleaning up nodes, machines and infra machines.
I0624 14:47:00.216565   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:00.217081   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-2f55v/test-mhc-vwksw/test-mhc-machine-6vxvl/"
E0624 14:47:00.254408   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-2f55v/test-cluster-6lrn5"
I0624 14:47:00.258548   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
E0624 14:47:00.258645   10465 machinehealthcheck_controller.go:128] controllers/MachineHealthCheck "msg"="Failed to fetch Cluster for MachineHealthCheck" "error"="Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "cluster"="test-cluster-6lrn5" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
E0624 14:47:00.258681   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machinehealthcheck" "name"="test-mhc-vwksw" "namespace"="test-mhc-2f55v"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0624 14:47:00.333887   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
inframachine created: test-mhc-machine-infra-nf4mx
machine created: test-mhc-machine-cdpgs
E0624 14:47:00.555695   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-96cjz/machine-reconcile-hf54b"
I0624 14:47:01.258942   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vwksw" "namespace"="test-mhc-2f55v" 
I0624 14:47:01.259055   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.274882   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0624 14:47:01.303474   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.304541   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.306285   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 4 lines ...
I0624 14:47:01.314890   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.317125   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.318683   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.320297   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.322492   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.333436   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
E0624 14:47:01.334328   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:01.335286   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.337060   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.338801   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.340647   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.345140   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:01.349247   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 435 lines ...
I0624 14:47:02.327075   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.328841   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.330549   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.332256   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.334551   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.340038   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
E0624 14:47:02.340107   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:02.342090   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.345147   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.347757   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.349527   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.351269   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:02.353154   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 498 lines ...
I0624 14:47:03.348269   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.349968   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.352894   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.353503   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.361383   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.363273   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.363560   10465 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-5xwff/test-mhc-2v4hw/test-mhc-machine-cdpgs/"
E0624 14:47:03.363715   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:03.381691   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.382044   10465 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-5xwff/test-mhc-2v4hw/test-mhc-machine-cdpgs/"
E0624 14:47:03.423781   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v44ck, got []"  "node"="test-mhc-node-v44ck"
node created: test-mhc-node-v44ck
I0624 14:47:03.431078   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
inframachine created: test-mhc-machine-infra-q98b4
machine created: test-mhc-machine-pg7jh
I0624 14:47:03.445863   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:03.450794   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 345 lines ...
I0624 14:47:04.353818   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.355695   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.357640   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.359627   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.361592   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.363546   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
E0624 14:47:04.364777   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:04.365604   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.367570   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.369488   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.371432   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.373274   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:04.375250   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 377 lines ...
I0624 14:47:05.406441   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.410391   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.412657   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.416825   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.419322   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.423360   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
E0624 14:47:05.424935   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:05.425273   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.426487   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.428703   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.435627   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.436847   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:05.437910   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 327 lines ...
I0624 14:47:06.423418   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.425625   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.434419   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.435500   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.437577   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.439758   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
E0624 14:47:06.440608   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:06.441678   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.442044   10465 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-5xwff/test-mhc-2v4hw/test-mhc-machine-pg7jh/"
I0624 14:47:06.452688   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.453150   10465 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-5xwff/test-mhc-2v4hw/test-mhc-machine-pg7jh/"
node created: test-mhc-node-x8ch5
E0624 14:47:06.461353   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-x8ch5, got []"  "node"="test-mhc-node-x8ch5"
I0624 14:47:06.472697   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
inframachine created: test-mhc-machine-infra-clwmf
I0624 14:47:06.490803   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:06.494614   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
machine created: test-mhc-machine-2c88q
I0624 14:47:06.501530   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 263 lines ...
I0624 14:47:07.439770   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.442601   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.445109   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.447639   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.451066   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.453301   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
E0624 14:47:07.453913   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:07.455161   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.458682   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.462479   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.463973   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.465649   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:07.467129   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 297 lines ...
I0624 14:47:08.500335   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.501875   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.512157   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.513661   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.535632   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.537312   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
E0624 14:47:08.543742   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:08.544357   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.567910   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.579147   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.582946   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.585716   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:08.588748   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
... skipping 269 lines ...
I0624 14:47:09.546540   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.549152   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.551681   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.560394   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.562507   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.565012   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.566872   10465 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-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/"
E0624 14:47:09.570668   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:09.577965   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.578557   10465 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-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/"
E0624 14:47:09.640918   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-b4fqk, got []"  "node"="test-mhc-node-b4fqk"
node created: test-mhc-node-b4fqk
Cleaning up nodes, machines and infra machines.
I0624 14:47:09.648983   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.649578   10465 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-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/test-mhc-node-b4fqk"
I0624 14:47:09.669276   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.669812   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/"
Cleaning up nodes, machines and infra machines.
I0624 14:47:09.681514   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.682136   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/"
I0624 14:47:09.684778   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.685705   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-cdpgs/"
I0624 14:47:09.707342   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/"
I0624 14:47:09.715160   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.715850   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/"
I0624 14:47:09.716199   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-cdpgs/"
I0624 14:47:09.716660   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-pg7jh/"
I0624 14:47:09.727763   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kzvjq" "namespace"="test-mhc-5xwff" "count"=2
I0624 14:47:09.727856   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-kzvjq" "namespace"="test-mhc-5xwff" "descendants"="Worker machines: test-mhc-machine-cdpgs,test-mhc-machine-pg7jh,test-mhc-machine-2c88q" "indirect descendants count"=1
I0624 14:47:09.733899   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kzvjq" "namespace"="test-mhc-5xwff" "count"=2
I0624 14:47:09.733967   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-kzvjq" "namespace"="test-mhc-5xwff" "descendants"="Worker machines: test-mhc-machine-2c88q,test-mhc-machine-cdpgs,test-mhc-machine-pg7jh" "indirect descendants count"=1
I0624 14:47:09.740155   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:09.740847   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-cdpgs/"
I0624 14:47:09.741312   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-pg7jh/"
I0624 14:47:09.741769   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5xwff/test-mhc-2v4hw/test-mhc-machine-2c88q/"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
E0624 14:47:09.746524   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-2v4hw\" not found" "controller"="machinehealthcheck" "name"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff"
inframachine created: test-mhc-machine-infra-nhp2n
machine created: test-mhc-machine-vvr2p
I0624 14:47:10.573375   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kzvjq" "machine"="test-mhc-machine-pg7jh" "namespace"="test-mhc-5xwff" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-x8ch5"}
E0624 14:47:10.626867   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-pg7jh\" not found" "controller"="machine" "name"="test-mhc-machine-pg7jh" "namespace"="test-mhc-5xwff"
I0624 14:47:10.746808   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v4hw" "namespace"="test-mhc-5xwff" 
I0624 14:47:10.746932   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:10.803426   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0624 14:47:10.849838   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:10.864166   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:10.874349   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:10.919418   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:11.000413   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:11.163472   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:11.484579   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:11.627298   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:12.125728   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:12.627817   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kzvjq" "machine"="test-mhc-machine-2c88q" "namespace"="test-mhc-5xwff" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-b4fqk"}
E0624 14:47:12.704641   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2c88q\" not found" "controller"="machine" "name"="test-mhc-machine-2c88q" "namespace"="test-mhc-5xwff"
I0624 14:47:13.406796   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:13.705049   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:14.705637   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kzvjq" "machine"="test-mhc-machine-cdpgs" "namespace"="test-mhc-5xwff" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-v44ck"}
I0624 14:47:14.734107   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kzvjq" "namespace"="test-mhc-5xwff" "count"=1
I0624 14:47:14.734193   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-kzvjq" "namespace"="test-mhc-5xwff" "descendants"="Worker machines: test-mhc-machine-cdpgs" "indirect descendants count"=0
E0624 14:47:14.746628   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cdpgs\" not found" "controller"="machine" "name"="test-mhc-machine-cdpgs" "namespace"="test-mhc-5xwff"
I0624 14:47:15.757078   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:15.764885   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:15.765212   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:15.808566   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:15.822959   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g7fwh, got []"  "node"="test-mhc-node-g7fwh"
node created: test-mhc-node-g7fwh
E0624 14:47:15.823771   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g7fwh, got []"  "node"="test-mhc-node-g7fwh"
I0624 14:47:15.830124   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
inframachine created: test-mhc-machine-infra-pbjhj
machine created: test-mhc-machine-z9dgh
I0624 14:47:15.878053   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:15.889505   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:15.894731   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:15.895842   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:15.904899   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:15.986397   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:16.147844   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:16.469238   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:16.765282   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:17.111602   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:17.779700   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:17.792901   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:17.801857   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:17.815794   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:17.824143   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:17.836021   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:17.839271   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:17.839593   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:17.860916   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:17.869377   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r77gw, got []"  "node"="test-mhc-node-r77gw"
node created: test-mhc-node-r77gw
E0624 14:47:17.869666   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r77gw, got []"  "node"="test-mhc-node-r77gw"
I0624 14:47:17.876511   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
inframachine created: test-mhc-machine-infra-j4r4r
machine created: test-mhc-machine-vbrbm
I0624 14:47:17.901175   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:18.091924   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:18.100634   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:18.392856   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:18.840053   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
E0624 14:47:19.750855   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5xwff/test-cluster-kzvjq"
I0624 14:47:19.852867   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:19.875041   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:19.886470   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:19.899253   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:19.905068   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:19.915967   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:19.922019   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:19.922396   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:19.957629   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
E0624 14:47:19.998969   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2c8z9, got []"  "node"="test-mhc-node-2c8z9"
node created: test-mhc-node-2c8z9
I0624 14:47:20.006612   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
Cleaning up nodes, machines and infra machines.
I0624 14:47:20.018027   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:20.032754   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
Cleaning up nodes, machines and infra machines.
... skipping 5 lines ...
inframachine created: test-mhc-machine-infra-tp29b
machine created: test-mhc-machine-q8rmd
I0624 14:47:20.246930   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:20.271639   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0624 14:47:20.394685   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9x4g" "namespace"="test-mhc-wtgx5" 
I0624 14:47:20.394853   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
E0624 14:47:20.922492   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:21.925953   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xrx8r" "machine"="test-mhc-machine-vvr2p" "namespace"="test-mhc-wtgx5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-g7fwh"}
E0624 14:47:21.977739   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vvr2p\" not found" "controller"="machine" "name"="test-mhc-machine-vvr2p" "namespace"="test-mhc-wtgx5"
I0624 14:47:22.978442   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xrx8r" "machine"="test-mhc-machine-z9dgh" "namespace"="test-mhc-wtgx5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-r77gw"}
E0624 14:47:23.041493   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-z9dgh\" not found" "controller"="machine" "name"="test-mhc-machine-z9dgh" "namespace"="test-mhc-wtgx5"
I0624 14:47:24.041965   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xrx8r" "machine"="test-mhc-machine-vbrbm" "namespace"="test-mhc-wtgx5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2c8z9"}
E0624 14:47:24.087124   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vbrbm\" not found" "controller"="machine" "name"="test-mhc-machine-vbrbm" "namespace"="test-mhc-wtgx5"
E0624 14:47:25.086023   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wtgx5/test-cluster-xrx8r"
I0624 14:47:25.096859   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
E0624 14:47:25.099631   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:25.100213   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
E0624 14:47:25.146856   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tn862, got []"  "node"="test-mhc-node-tn862"
node created: test-mhc-node-tn862
I0624 14:47:25.154473   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
inframachine created: test-mhc-machine-infra-vtcgn
machine created: test-mhc-machine-k6qdq
I0624 14:47:25.195667   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:25.202477   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:25.203591   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
E0624 14:47:26.100034   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:27.113133   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.122806   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.135112   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.142600   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.165083   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.176046   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.186487   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.206372   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
node created: test-mhc-node-fjbfk
E0624 14:47:27.221741   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjbfk, got []"  "node"="test-mhc-node-fjbfk"
I0624 14:47:27.229160   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
inframachine created: test-mhc-machine-infra-b2k57
machine created: test-mhc-machine-lrndk
I0624 14:47:27.256758   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.264147   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.273257   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
... skipping 5 lines ...
Cleaning up nodes, machines and infra machines.
I0624 14:47:27.392894   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.395821   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
Cleaning up nodes, machines and infra machines.
I0624 14:47:27.405551   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.408965   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.409506   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k8x6w/test-mhc-hwbzq/test-mhc-machine-q8rmd/"
I0624 14:47:27.416163   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jz42r" "machine"="test-mhc-machine-lrndk" "namespace"="test-mhc-k8x6w" "cause"="noderef is nil" "node"=null
I0624 14:47:27.434594   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.435287   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k8x6w/test-mhc-hwbzq/test-mhc-machine-q8rmd/"
I0624 14:47:27.436371   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k8x6w/test-mhc-hwbzq/test-mhc-machine-k6qdq/"
I0624 14:47:27.489418   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jz42r" "namespace"="test-mhc-k8x6w" "count"=3
I0624 14:47:27.489492   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jz42r" "namespace"="test-mhc-k8x6w" "descendants"="Worker machines: test-mhc-machine-q8rmd,test-mhc-machine-k6qdq,test-mhc-machine-lrndk" "indirect descendants count"=0
I0624 14:47:27.498944   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w" 
I0624 14:47:27.499683   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k8x6w/test-mhc-hwbzq/test-mhc-machine-k6qdq/"
E0624 14:47:27.499930   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lrndk\" not found" "controller"="machine" "name"="test-mhc-machine-lrndk" "namespace"="test-mhc-k8x6w"
I0624 14:47:27.500097   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k8x6w/test-mhc-hwbzq/test-mhc-machine-q8rmd/"
E0624 14:47:27.509719   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-hwbzq\" not found" "controller"="machinehealthcheck" "name"="test-mhc-hwbzq" "namespace"="test-mhc-k8x6w"
I0624 14:47:27.510531   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jz42r" "namespace"="test-mhc-k8x6w" "count"=2
I0624 14:47:27.510582   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jz42r" "namespace"="test-mhc-k8x6w" "descendants"="Worker machines: test-mhc-machine-k6qdq,test-mhc-machine-q8rmd" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-swpmz
... skipping 7 lines ...
I0624 14:47:28.566861   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.568613   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.570272   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.571933   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.576188   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.577858   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
E0624 14:47:28.578017   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-q8rmd\" not found" "controller"="machine" "name"="test-mhc-machine-q8rmd" "namespace"="test-mhc-k8x6w"
I0624 14:47:28.579590   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.581819   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.583567   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.585408   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.587872   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:28.589547   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
... skipping 521 lines ...
I0624 14:47:29.620005   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.621589   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.623300   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.625026   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.626741   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.628842   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
E0624 14:47:29.630132   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-k6qdq\" not found" "controller"="machine" "name"="test-mhc-machine-k6qdq" "namespace"="test-mhc-k8x6w"
I0624 14:47:29.630424   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.641306   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.643561   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.645971   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.647798   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:29.649600   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
... skipping 469 lines ...
I0624 14:47:30.635697   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.637433   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.639976   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.640536   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.641666   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.643416   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
E0624 14:47:30.645500   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:30.646194   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.651376   10465 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-j4tg6/test-mhc-pcfmh/test-mhc-machine-5w8hd/"
E0624 14:47:30.660224   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hbqmm, got []"  "node"="test-mhc-node-hbqmm"
node created: test-mhc-node-hbqmm
E0624 14:47:30.661360   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hbqmm, got []"  "node"="test-mhc-node-hbqmm"
I0624 14:47:30.662743   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.663008   10465 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-j4tg6/test-mhc-pcfmh/test-mhc-machine-5w8hd/"
I0624 14:47:30.668930   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.699853   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.700824   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.706777   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.707140   10465 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-j4tg6/test-mhc-pcfmh/test-mhc-machine-5w8hd/test-mhc-node-hbqmm"
I0624 14:47:30.726400   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.726804   10465 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-j4tg6/test-mhc-pcfmh/test-mhc-machine-5w8hd/test-mhc-node-hbqmm"
Cleaning up nodes, machines and infra machines.
I0624 14:47:30.732984   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.733347   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-j4tg6/test-mhc-pcfmh/test-mhc-machine-5w8hd/"
I0624 14:47:30.749030   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.749440   10465 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-j4tg6/test-mhc-pcfmh/test-mhc-machine-5w8hd/"
I0624 14:47:30.750668   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5svbh" "namespace"="test-mhc-j4tg6" "descendants"="Worker machines: test-mhc-machine-5w8hd" "indirect descendants count"=1
I0624 14:47:30.754863   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5svbh" "namespace"="test-mhc-j4tg6" "descendants"="Worker machines: test-mhc-machine-5w8hd" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0624 14:47:30.756908   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pcfmh" "namespace"="test-mhc-j4tg6" 
I0624 14:47:30.888619   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" "creating"=1 "need"=1
I0624 14:47:30.888668   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" 
I0624 14:47:30.901724   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-dsq8b-7n6f9\"" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" 
I0624 14:47:30.978399   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:30.996948   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0624 14:47:31.117877   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:31.122440   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
E0624 14:47:31.646073   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:32.118104   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
E0624 14:47:32.523056   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-k8x6w/test-cluster-jz42r"
I0624 14:47:32.646630   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-5svbh" "machine"="test-mhc-machine-5w8hd" "namespace"="test-mhc-j4tg6" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hbqmm"}
E0624 14:47:32.706096   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5w8hd\" not found" "controller"="machine" "name"="test-mhc-machine-5w8hd" "namespace"="test-mhc-j4tg6"
I0624 14:47:33.119162   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.716234   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.716723   10465 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.721168   10465 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.721373   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.728699   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
... skipping 4 lines ...
I0624 14:47:33.742494   10465 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.747793   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.747841   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.752189   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:33.752227   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.120026   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.120379   10465 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-krlh7/test-mhc-j6kwz/mhc-ms-dsq8b-7n6f9/"
I0624 14:47:34.127434   10465 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.131187   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.131257   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.132453   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.132824   10465 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-krlh7/test-mhc-j6kwz/mhc-ms-dsq8b-7n6f9/"
I0624 14:47:34.136569   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j6kwz" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.136638   10465 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.136925   10465 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-krlh7/test-mhc-j6kwz/mhc-ms-dsq8b-7n6f9/"
I0624 14:47:34.145245   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.145298   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" 
I0624 14:47:34.242177   10465 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-dds94" "namespace"="test-mhc-krlh7" "count"=1
I0624 14:47:34.242239   10465 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-dds94" "namespace"="test-mhc-krlh7" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-dsq8b"
I0624 14:47:34.245113   10465 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-dsq8b" "namespace"="test-mhc-krlh7" "machine"="mhc-ms-dsq8b-7n6f9"
I0624 14:47:34.247311   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dds94" "namespace"="test-mhc-krlh7" "descendants"="Machine sets: mhc-ms-dsq8b;Worker machines: mhc-ms-dsq8b-7n6f9" "indirect descendants count"=1
... skipping 4 lines ...
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0624 14:47:34.406806   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
inframachine created: test-mhc-machine-infra-mx7b5
I0624 14:47:34.420308   10465 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-s6f9x
I0624 14:47:34.442632   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dds94" "machine"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7" "cause"="cluster is being deleted" "node"=null
E0624 14:47:34.470300   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-dsq8b-7n6f9\" not found" "controller"="machine" "name"="mhc-ms-dsq8b-7n6f9" "namespace"="test-mhc-krlh7"
node created: test-mhc-node-4pjwp
E0624 14:47:34.526930   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4pjwp, got []"  "node"="test-mhc-node-4pjwp"
E0624 14:47:34.526996   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4pjwp, got []"  "node"="test-mhc-node-4pjwp"
E0624 14:47:34.527033   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4pjwp, got []"  "node"="test-mhc-node-4pjwp"
I0624 14:47:34.559441   10465 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-s6f9x" "target"="test-mhc-59xzs/test-mhc-nwkgs/test-mhc-machine-s6f9x/"
I0624 14:47:34.587518   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
I0624 14:47:34.603460   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
I0624 14:47:34.605552   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
I0624 14:47:34.610228   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
I0624 14:47:34.616808   10465 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-s6f9x" "target"="test-mhc-59xzs/test-mhc-nwkgs/test-mhc-machine-s6f9x/test-mhc-node-4pjwp"
I0624 14:47:34.633383   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
Cleaning up nodes, machines and infra machines.
I0624 14:47:34.650863   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
I0624 14:47:34.656416   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
I0624 14:47:34.659423   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nwkgs" "namespace"="test-mhc-59xzs" 
I0624 14:47:34.665701   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xmn4q" "namespace"="test-mhc-59xzs" "descendants"="Worker machines: test-mhc-machine-s6f9x" "indirect descendants count"=1
... skipping 427 lines ...
I0624 14:47:35.491989   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.493600   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.495357   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.497202   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.499503   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.501392   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
E0624 14:47:35.502281   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-s6f9x\" not found" "controller"="machine" "name"="test-mhc-machine-s6f9x" "namespace"="test-mhc-59xzs"
I0624 14:47:35.503047   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.504681   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.506326   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.507931   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.509768   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.511341   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
... skipping 133 lines ...
I0624 14:47:35.756030   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.757656   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.759230   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.760843   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.762536   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.764651   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
E0624 14:47:35.766086   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-j4tg6/test-cluster-5svbh"
I0624 14:47:35.766204   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.767777   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.769423   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.771101   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.772782   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:35.774400   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
... skipping 402 lines ...
I0624 14:47:36.504772   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.506381   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.509082   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.509803   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.510858   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.512758   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
E0624 14:47:36.513437   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
I0624 14:47:36.513577   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.517112   10465 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-jbz8t" "target"="test-mhc-kkjvq/test-mhc-mznzb/test-mhc-machine-jbz8t/"
node created: test-mhc-node-bxqtr
E0624 14:47:36.518150   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bxqtr, got []"  "node"="test-mhc-node-bxqtr"
E0624 14:47:36.518223   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bxqtr, got []"  "node"="test-mhc-node-bxqtr"
E0624 14:47:36.518619   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bxqtr, got []"  "node"="test-mhc-node-bxqtr"
I0624 14:47:36.712981   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.729783   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.731749   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.745143   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.748279   10465 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-jbz8t" "target"="test-mhc-kkjvq/test-mhc-mznzb/test-mhc-machine-jbz8t/test-mhc-node-bxqtr"
I0624 14:47:36.760770   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.767048   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.769953   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.787534   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
Cleaning up nodes, machines and infra machines.
I0624 14:47:36.794755   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
I0624 14:47:36.800118   10465 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-jbz8t" "target"="test-mhc-kkjvq/test-mhc-mznzb/test-mhc-machine-jbz8t/"
I0624 14:47:36.805888   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k4zr2" "namespace"="test-mhc-kkjvq" "descendants"="Worker machines: test-mhc-machine-jbz8t" "indirect descendants count"=1
I0624 14:47:36.811571   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k4zr2" "namespace"="test-mhc-kkjvq" "descendants"="Worker machines: test-mhc-machine-jbz8t" "indirect descendants count"=1
E0624 14:47:36.814331   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-mznzb\" not found" "controller"="machinehealthcheck" "name"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq"
--- PASS: TestMachineHealthCheck_Reconcile (38.62s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.14s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.17s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (0.96s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.16s)
... 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.42s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.14s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0624 14:47:36.816279   10465 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
E0624 14:47:36.817405   10465 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
E0624 14:47:36.818677   10465 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0624 14:47:36.818847   10465 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
E0624 14:47:36.819125   10465 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
I0624 14:47:36.821234   10465 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0624 14:47:36.821658   10465 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0624 14:47:36.822792   10465 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
E0624 14:47:36.828660   10465 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
E0624 14:47:36.829713   10465 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 65 lines ...
I0624 14:47:36.922397   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-9qkbv-6hgkl\"" "machineset"="ms-9qkbv" "namespace"="ms-test" 
I0624 14:47:36.922443   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-9qkbv" "namespace"="ms-test" 
I0624 14:47:36.934984   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-9qkbv-rgqs9\"" "machineset"="ms-9qkbv" "namespace"="ms-test" 
I0624 14:47:37.036201   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-9qkbv" "namespace"="ms-test" "creating"=1 "need"=2
I0624 14:47:37.036251   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-9qkbv" "namespace"="ms-test" 
I0624 14:47:37.050082   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-9qkbv-8fp5v\"" "machineset"="ms-9qkbv" "namespace"="ms-test" 
E0624 14:47:37.161125   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.161156   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.161215   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.264937   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.264945   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.264984   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.264939   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.265001   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.265008   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-rgqs9-75bv9, got []"  "node"="ms-9qkbv-rgqs9-75bv9"
E0624 14:47:37.294324   10465 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-9qkbv-rgqs9-75bv9 for machine ms-test/ms-9qkbv-rgqs9: the cache is not started, can not read objects" "machineset"="ms-9qkbv" "namespace"="ms-test" 
E0624 14:47:37.299271   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.299374   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.299427   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.301782   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.301820   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.301825   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.301824   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.301860   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
E0624 14:47:37.301876   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9qkbv-8fp5v-q26ps, got []"  "node"="ms-9qkbv-8fp5v-q26ps"
I0624 14:47:37.422259   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9qkbv-8fp5v,ms-9qkbv-rgqs9" "indirect descendants count"=2
I0624 14:47:37.425719   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9qkbv-8fp5v,ms-9qkbv-rgqs9" "indirect descendants count"=2
•I0624 14:47:37.482492   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0624 14:47:37.482544   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.492542   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-9kkqm-6657c7fddb-rqs8v\"" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.492600   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.501639   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-9kkqm-6657c7fddb-dd6mh\"" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.513944   10465 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k4zr2" "machine"="test-mhc-machine-jbz8t" "namespace"="test-mhc-kkjvq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-bxqtr"}
E0624 14:47:37.545914   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jbz8t\" not found" "controller"="machine" "name"="test-mhc-machine-jbz8t" "namespace"="test-mhc-kkjvq"
I0624 14:47:37.610135   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0624 14:47:37.610184   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.618632   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-9kkqm-6657c7fddb-z7g9g\"" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.618698   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.629405   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-9kkqm-6657c7fddb-8k656\"" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.677474   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0624 14:47:37.677522   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.689883   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9kkqm-6657c7fddb-f6lkv\"" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" 
I0624 14:47:37.786423   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0624 14:47:37.786573   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" 
I0624 14:47:37.797561   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9kkqm-cdfc6fd6c-46qgj\"" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" 
I0624 14:47:37.814543   10465 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mznzb" "namespace"="test-mhc-kkjvq" 
E0624 14:47:37.879756   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.879965   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.880154   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.948115   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.948176   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.948176   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.948192   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.948220   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.948227   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-46qgj-zcbjb, got []"  "node"="md-9kkqm-cdfc6fd6c-46qgj-zcbjb"
E0624 14:47:37.969011   10465 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-9kkqm-cdfc6fd6c-46qgj-zcbjb for machine md-test/md-9kkqm-cdfc6fd6c-46qgj: the cache is not started, can not read objects" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" 
I0624 14:47:37.992486   10465 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0624 14:47:37.992528   10465 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0624 14:47:37.997797   10465 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "machine"="md-9kkqm-6657c7fddb-z7g9g"
I0624 14:47:38.014317   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0624 14:47:38.014360   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" 
I0624 14:47:38.026057   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9kkqm-cdfc6fd6c-b6p9z\"" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" 
E0624 14:47:38.077846   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.077983   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.078021   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.081015   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.081043   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.081071   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.081015   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.081085   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
E0624 14:47:38.081096   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-b6p9z-xkhvt, got []"  "node"="md-9kkqm-cdfc6fd6c-b6p9z-xkhvt"
I0624 14:47:38.111796   10465 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0624 14:47:38.111839   10465 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0624 14:47:38.115876   10465 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "machine"="md-9kkqm-6657c7fddb-8k656"
I0624 14:47:38.132616   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0624 14:47:38.132658   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" 
I0624 14:47:38.140842   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9kkqm-cdfc6fd6c-j9bfk\"" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" 
E0624 14:47:38.208509   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.208660   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.209146   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.312091   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.312156   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.312163   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.312196   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.312211   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
E0624 14:47:38.312246   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-cdfc6fd6c-j9bfk-92qj2, got []"  "node"="md-9kkqm-cdfc6fd6c-j9bfk-92qj2"
I0624 14:47:38.351361   10465 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0624 14:47:38.351400   10465 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0624 14:47:38.355207   10465 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9kkqm-6657c7fddb" "namespace"="md-test" "machine"="md-9kkqm-6657c7fddb-f6lkv"
E0624 14:47:38.546376   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
I0624 14:47:38.599594   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0624 14:47:38.599744   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" 
I0624 14:47:38.612355   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9kkqm-74d45c49c5-cmzth\"" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" 
E0624 14:47:38.696785   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.697181   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.697365   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.700162   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.700253   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.700322   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.700336   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.700361   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
E0624 14:47:38.700379   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-cmzth-5nkjr, got []"  "node"="md-9kkqm-74d45c49c5-cmzth-5nkjr"
I0624 14:47:38.730546   10465 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0624 14:47:38.730659   10465 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0624 14:47:38.736701   10465 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "machine"="md-9kkqm-cdfc6fd6c-j9bfk"
I0624 14:47:38.753259   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0624 14:47:38.753317   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" 
I0624 14:47:38.762154   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9kkqm-74d45c49c5-gh5wc\"" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" 
E0624 14:47:38.823958   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.823958   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.824033   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.826924   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.826980   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.827235   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.827242   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.827289   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
E0624 14:47:38.827303   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-gh5wc-97qjb, got []"  "node"="md-9kkqm-74d45c49c5-gh5wc-97qjb"
I0624 14:47:38.911116   10465 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0624 14:47:38.911152   10465 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0624 14:47:38.915494   10465 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "machine"="md-9kkqm-cdfc6fd6c-b6p9z"
I0624 14:47:39.024231   10465 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0624 14:47:39.024380   10465 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" 
I0624 14:47:39.032825   10465 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9kkqm-74d45c49c5-s6zjf\"" "machineset"="md-9kkqm-74d45c49c5" "namespace"="md-test" 
E0624 14:47:39.074064   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.074222   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.074539   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.077390   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.077437   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.077446   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.077481   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.077534   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
E0624 14:47:39.077578   10465 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9kkqm-74d45c49c5-s6zjf-gwg94, got []"  "node"="md-9kkqm-74d45c49c5-s6zjf-gwg94"
I0624 14:47:39.181056   10465 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0624 14:47:39.181095   10465 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0624 14:47:39.186861   10465 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9kkqm-cdfc6fd6c" "namespace"="md-test" "machine"="md-9kkqm-cdfc6fd6c-46qgj"
I0624 14:47:39.236760   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9kkqm-cdfc6fd6c,md-9kkqm-74d45c49c5;Worker machines: md-9kkqm-74d45c49c5-gh5wc,md-9kkqm-74d45c49c5-cmzth,md-9kkqm-6657c7fddb-rqs8v,md-9kkqm-6657c7fddb-dd6mh,md-9kkqm-74d45c49c5-s6zjf" "indirect descendants count"=7
I0624 14:47:39.240356   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9kkqm-74d45c49c5,md-9kkqm-cdfc6fd6c;Worker machines: md-9kkqm-6657c7fddb-dd6mh,md-9kkqm-74d45c49c5-s6zjf,md-9kkqm-74d45c49c5-gh5wc,md-9kkqm-74d45c49c5-cmzth,md-9kkqm-6657c7fddb-rqs8v" "indirect descendants count"=7
•E0624 14:47:39.265937   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-krlh7/test-cluster-dds94"
•E0624 14:47:39.363096   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-db6vc\" not found" "controller"="cluster" "name"="test1-db6vc" "namespace"="default"
I0624 14:47:39.703460   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:39.703498   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:39.722573   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
I0624 14:47:39.722623   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
E0624 14:47:39.757322   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-cmzth\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-cmzth" "namespace"="md-test"
E0624 14:47:40.422012   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-59xzs/test-cluster-xmn4q"
•I0624 14:47:40.481612   10465 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jqdc5" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0624 14:47:40.598157   10465 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jqdc5" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0624 14:47:40.603200   10465 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-jqdc5" "namespace"="default"
E0624 14:47:40.787515   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-gh5wc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-gh5wc" "namespace"="md-test"
E0624 14:47:41.617111   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
•E0624 14:47:41.813230   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-s6zjf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-s6zjf" "namespace"="md-test"
E0624 14:47:42.630252   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-ltp5b\" not found" "controller"="cluster" "name"="test3-ltp5b" "namespace"="default"
I0624 14:47:42.838861   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:42.838899   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:42.842632   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
I0624 14:47:42.842668   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
E0624 14:47:42.846741   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-cmzth\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-cmzth" "namespace"="md-test"
E0624 14:47:43.630962   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
E0624 14:47:43.852098   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-gh5wc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-gh5wc" "namespace"="md-test"
E0624 14:47:44.649229   10465 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kkjvq/test-cluster-k4zr2"
I0624 14:47:44.649456   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9qkbv-8fp5v,ms-9qkbv-rgqs9" "indirect descendants count"=2
E0624 14:47:44.649934   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
•E0624 14:47:44.857380   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-s6zjf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-s6zjf" "namespace"="md-test"
I0624 14:47:45.650641   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9kkqm-74d45c49c5,md-9kkqm-cdfc6fd6c;Worker machines: md-9kkqm-74d45c49c5-gh5wc,md-9kkqm-74d45c49c5-cmzth,md-9kkqm-6657c7fddb-rqs8v,md-9kkqm-6657c7fddb-dd6mh,md-9kkqm-74d45c49c5-s6zjf" "indirect descendants count"=7
E0624 14:47:45.655203   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
E0624 14:47:45.870450   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-cmzth\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-cmzth" "namespace"="md-test"
E0624 14:47:46.656080   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
I0624 14:47:46.875562   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:46.875686   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:46.880401   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
I0624 14:47:46.880450   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
E0624 14:47:46.885167   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-gh5wc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-gh5wc" "namespace"="md-test"
E0624 14:47:47.666045   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
•E0624 14:47:47.889988   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-s6zjf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-s6zjf" "namespace"="md-test"
E0624 14:47:48.666788   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
E0624 14:47:48.895050   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-cmzth\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-cmzth" "namespace"="md-test"
E0624 14:47:49.667607   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
E0624 14:47:49.895612   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-6vxvl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-6vxvl" "namespace"="test-mhc-2f55v"
E0624 14:47:50.679498   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
E0624 14:47:50.900714   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-gh5wc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-gh5wc" "namespace"="md-test"
I0624 14:47:51.680049   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9qkbv-8fp5v,ms-9qkbv-rgqs9" "indirect descendants count"=2
E0624 14:47:51.680524   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
I0624 14:47:51.905192   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:51.905238   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:51.909144   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
I0624 14:47:51.909183   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
E0624 14:47:51.913333   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-s6zjf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-s6zjf" "namespace"="md-test"
I0624 14:47:52.681123   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9kkqm-74d45c49c5,md-9kkqm-cdfc6fd6c;Worker machines: md-9kkqm-74d45c49c5-gh5wc,md-9kkqm-74d45c49c5-cmzth,md-9kkqm-6657c7fddb-rqs8v,md-9kkqm-6657c7fddb-dd6mh,md-9kkqm-74d45c49c5-s6zjf" "indirect descendants count"=7
E0624 14:47:52.681888   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
E0624 14:47:52.913682   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6lrn5\" for machine \"test-mhc-machine-456wl\" in namespace \"test-mhc-2f55v\": Cluster.cluster.x-k8s.io \"test-cluster-6lrn5\" not found" "controller"="machine" "name"="test-mhc-machine-456wl" "namespace"="test-mhc-2f55v"
E0624 14:47:53.682623   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
E0624 14:47:53.918777   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-cmzth\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-cmzth" "namespace"="md-test"
E0624 14:47:54.683446   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
E0624 14:47:54.935635   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-gh5wc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-gh5wc" "namespace"="md-test"
E0624 14:47:55.684278   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
E0624 14:47:55.941255   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-s6zjf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-s6zjf" "namespace"="md-test"
E0624 14:47:56.685363   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
I0624 14:47:56.946755   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:56.946819   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:47:56.951203   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
I0624 14:47:56.951278   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
E0624 14:47:56.956194   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-cmzth\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-cmzth" "namespace"="md-test"
E0624 14:47:57.686124   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
I0624 14:47:57.970922   10465 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-qmsw7" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0624 14:47:57.989614   10465 machine_controller_noderef.go:73] controllers/Machine "msg"="Failed to retrieve Node by ProviderID" "error"="the cache is not started, can not read objects" "machine"="test6-qmsw7" "namespace"="default" 
E0624 14:47:58.004193   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\", the cache is not started, can not read objects]" "controller"="machine" "name"="test6-qmsw7" "namespace"="default"
I0624 14:47:58.686768   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9qkbv-8fp5v,ms-9qkbv-rgqs9" "indirect descendants count"=2
E0624 14:47:58.687489   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
E0624 14:47:59.009599   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-gh5wc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-gh5wc" "namespace"="md-test"
I0624 14:47:59.688176   10465 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9kkqm-74d45c49c5,md-9kkqm-cdfc6fd6c;Worker machines: md-9kkqm-6657c7fddb-rqs8v,md-9kkqm-6657c7fddb-dd6mh,md-9kkqm-74d45c49c5-s6zjf,md-9kkqm-74d45c49c5-gh5wc,md-9kkqm-74d45c49c5-cmzth" "indirect descendants count"=7
E0624 14:47:59.688732   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
E0624 14:48:00.015304   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-s6zjf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-s6zjf" "namespace"="md-test"
E0624 14:48:00.689412   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jqdc5: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jqdc5" "namespace"="default"
E0624 14:48:01.024070   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9kkqm-74d45c49c5-cmzth\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9kkqm-74d45c49c5-cmzth" "namespace"="md-test"
E0624 14:48:01.690169   10465 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2hrc9: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2hrc9" "namespace"="default"
I0624 14:48:02.029528   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:48:02.029570   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-rqs8v" "namespace"="md-test" 
I0624 14:48:02.033696   10465 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
I0624 14:48:02.033741   10465 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9kkqm-6657c7fddb-dd6mh" "namespace"="md-test" 
I0624 14:48:02.048548   10465 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-qmsw7" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0624 14:48:02.048919   10465 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-qmsw7" "namespace"="default" "noderef"="id-node-1"
E0624 14:48:02.060209   10465 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-qmsw7" "namespace"="default"

------------------------------
• [SLOW TEST:15.065 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 25 lines ...
I0624 14:48:02.814278   10465 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"
•I0624 14:48:02.815746   10465 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"
I0624 14:48:02.816550   10465 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"
I0624 14:48:02.817192   10465 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0624 14:48:02.817228   10465 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0624 14:48:02.817779   10465 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0624 14:48:02.819031   10465 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 25.990 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (25.99s)
PASS
Tearing down test suite
I0624 14:48:02.820612   10465 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0624 14:48:02.820654   10465 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0624 14:48:02.820669   10465 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0624 14:48:02.820683   10465 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0624 14:48:02.820698   10465 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0624 14:48:02.820719   10465 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0624 14:48:02.820792   10465 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0624 14:48:02.821104   10465 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0624 14:48:02.821148   10465 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-943456759/tls.crt: no such file or directory"  
E0624 14:48:02.870536   10465 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:46863/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1273&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:46863: connect: connection refused
E0624 14:48:02.870576   10465 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:46863/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1273&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:46863: connect: connection refused
E0624 14:48:02.871363   10465 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:46863/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1273&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:46863: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	82.974s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 260 lines ...
I0624 14:46:53.754056   10999 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39875
I0624 14:46:53.754299   10999 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0624 14:46:53.767792   10999 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}}}
I0624 14:46:53.968205   10999 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0624 14:46:53.968261   10999 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0624 14:46:54.173197   10999 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0624 14:46:56.209827   10999 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-2qn6d/test-cluster"
•E0624 14:46:56.676542   10999 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-djcgc/test-cluster"
•E0624 14:46:57.219810   10999 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:44441/?timeout=50ms: dial tcp 127.0.0.1:44441: connect: connection refused"  "cluster"="cluster-cache-test-jm57j/test-cluster"
•I0624 14:46:57.437750   10999 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0624 14:46:57.638138   10999 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0624 14:46:57.638199   10999 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0624 14:46:57.638276   10999 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0624 14:46:58.164027   10999 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0624 14:46:58.164049   10999 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0624 14:46:58.164104   10999 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-193831062/tls.crt: no such file or directory"  
I0624 14:46:58.164135   10999 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0624 14:46:58.261402   10999 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:40743/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:40743: connect: connection refused


Ran 5 of 5 Specs in 15.842 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.84s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	15.966s
?   	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
I0624 14:47:07.685092   11676 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
E0624 14:47:07.686246   11676 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
I0624 14:47:07.686867   11676 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0624 14:47:07.687009   11676 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0624 14:47:20.665019   11676 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
I0624 14:47:20.665164   11676 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: 1656082013
Will run 1 of 1 specs

E0624 14:47:20.698363   11676 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-zbo5gx\" not found" "kubeadmControlPlane"="kcp-foo-zbo5gx" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.030 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.03s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0624 14:47:20.700435   11676 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-9pgokj" "kubeadmControlPlane"="kcp-foo-9pgokj" "namespace"="test" 
I0624 14:47:21.884037   11676 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-9pgokj" "kubeadmControlPlane"="kcp-foo-9pgokj" "namespace"="test" "needRollout"=["kcp-foo-9pgokj-z7qg6"]
I0624 14:47:21.884164   11676 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-9pgokj" "kubeadmControlPlane"="kcp-foo-9pgokj" "namespace"="test" "failures"="[machine kcp-foo-9pgokj-7sbq9 does not have APIServerPodHealthy condition, machine kcp-foo-9pgokj-7sbq9 does not have ControllerManagerPodHealthy condition, machine kcp-foo-9pgokj-7sbq9 does not have SchedulerPodHealthy condition, machine kcp-foo-9pgokj-7sbq9 does not have EtcdPodHealthy condition, machine kcp-foo-9pgokj-7sbq9 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.19s)
... skipping 60 lines ...
==================================
Random Seed: 1656082012
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 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: 1656082012
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 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
E0624 14:47:05.312131   11635 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"  
E0624 14:47:13.635177   11635 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"  
E0624 14:47:22.621142   11635 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"  
E0624 14:47:33.751376   11635 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"  
E0624 14:47:50.224599   11635 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"  
E0624 14:48:03.233161   11635 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"  
E0624 14:48:20.880581   11635 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"  
E0624 14:48:41.803886   11635 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"  
E0624 14:49:12.820510   11635 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"  
E0624 14:49:57.977781   11635 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 383 lines ...
I0624 14:47:14.970773   11899 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0624 14:47:15.070494   11899 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0624 14:47:15.175403   11899 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0624 14:47:15.175474   11899 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0624 14:47:15.175507   11899 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0624 14:47:15.271881   11899 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-bnnv99"} 
E0624 14:47:15.312668   11899 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"
•I0624 14:47:16.400119   11899 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-w4vgqr"} 
E0624 14:47:16.438004   11899 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"
•E0624 14:47:17.551310   11899 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"
E0624 14:47:18.570163   11899 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"
•E0624 14:47:19.727691   11899 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"
•E0624 14:47:20.780710   11899 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"
E0624 14:47:21.795978   11899 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"
•I0624 14:47:21.797819   11899 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0624 14:47:21.797838   11899 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0624 14:47:21.797864   11899 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0624 14:47:21.797890   11899 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-370246372/tls.crt: no such file or directory"  
E0624 14:47:21.797912   11899 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0624 14:47:21.797931   11899 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-370246372/tls.crt: no such file or directory"  
I0624 14:47:21.797940   11899 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 5 of 5 Specs in 20.138 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.14s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	20.274s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.01s)
=== 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
E0624 14:47:05.604511   12146 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 92 lines ...
•I0624 14:47:16.879194   12146 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0624 14:47:16.960827   12146 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0624 14:47:16.966921   12146 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0624 14:47:17.006058   12146 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0624 14:47:17.036887   12146 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}}}
I0624 14:47:17.047431   12146 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0624 14:47:17.049982   12146 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0624 14:47:17.050043   12146 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-035028887/tls.crt: no such file or directory"  
E0624 14:47:17.050073   12146 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0624 14:47:17.050092   12146 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-035028887/tls.crt: no such file or directory"  
I0624 14:47:17.050205   12146 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 11.469 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.47s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.721s
?   	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 210 lines ...
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39
  Should patch a clusterv1.Cluster
  /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:411
    updating both spec, status, and adding a condition [It]
    /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:550

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 29 lines ...
•I0624 14:47:41.734599   15051 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

[Fail] Patch Helper Should patch a clusterv1.Cluster [It] updating both spec, status, and adding a condition 
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:580

Ran 14 of 14 Specs in 7.914 seconds
FAIL! -- 13 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestPatch (7.91s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
    --- PASS: TestToUnstructured/with_an_unstructured_object (0.00s)
... skipping 2 lines ...
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields
--- PASS: TestUnsafeFocusedUnstructured (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=spec,_should_only_return_spec_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields (0.00s)
FAIL
FAIL	sigs.k8s.io/cluster-api/util/patch	7.952s
?   	sigs.k8s.io/cluster-api/util/predicates	[no test files]
?   	sigs.k8s.io/cluster-api/util/record	[no test files]
=== RUN   TestSortForCreate
--- PASS: TestSortForCreate (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/resource	0.008s
... skipping 88 lines ...
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#01 (0.00s)
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#02 (0.00s)
=== RUN   TestFromUnstructured
--- PASS: TestFromUnstructured (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/yaml	0.037s
FAIL
make: *** [Makefile:116: test] Error 1