This job view page is being replaced by Spyglass soon. Check out the new job view.
PRsbueringer: ✨ v0.3.x: KCP: block mgmt cluster updates to v1.22.0
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2021-07-26 15:09
Elapsed5m9s
Revision0ea76dfd28bec8f5ad0cf2d96e3731b656540ba3
Refs 5013

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0726 15:12:23.033729    8607 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0726 15:12:23.034232    8607 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0726 15:12:23.035067    8607 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0726 15:12:23.035273    8607 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=33873
I0726 15:12:23.035580    8607 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0726 15:12:23.567097    8607 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" 
•E0726 15:12:23.581443    8607 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:12:23.581527    8607 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-843260876/tls.crt: no such file or directory"  
E0726 15:12:23.581555    8607 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:12:23.581586    8607 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-843260876/tls.crt: no such file or directory"  
I0726 15:12:23.581693    8607 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 11.681 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.68s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	66.271s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 310 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 ...
I0726 15:11:53.327582   10635 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":{}}}
I0726 15:11:53.327652   10635 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}}}
I0726 15:11:53.327686   10635 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0726 15:11:53.327723   10635 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0726 15:11:53.327517   10635 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0726 15:11:53.328164   10635 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2021/07/26 15:11:53 http: TLS handshake error from 127.0.0.1:55790: 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
I0726 15:11:53.826248   10635 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"
I0726 15:11:53.829224   10635 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
I0726 15:11:53.866613   10635 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
I0726 15:11:53.868261   10635 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"
E0726 15:11:53.868591   10635 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
I0726 15:11:53.869087   10635 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
I0726 15:11:54.077615   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0726 15:11:54.080605   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0726 15:11:54.134147   10635 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-k6tx4" "namespace"="test-machine-watches-prt7f" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0726 15:11:54.134238   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0726 15:11:54.246181   10635 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-k6tx4" "namespace"="test-machine-watches-prt7f" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0726 15:11:54.246273   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0726 15:11:54.353363   10635 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-k6tx4" "namespace"="test-machine-watches-prt7f" "noderef"="node-1"
E0726 15:11:54.382202   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0726 15:11:54.382270   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0726 15:11:54.496381   10635 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-k6tx4\" in namespace \"test-machine-watches-prt7f\", requeuing: requeue in 1s"  
E0726 15:11:54.511978   10635 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-k6tx4\" in namespace \"test-machine-watches-prt7f\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-k6tx4\" in namespace \"test-machine-watches-prt7f\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-k6tx4" "namespace"="test-machine-watches-prt7f"
--- PASS: TestWatches (0.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
I0726 15:11:54.636020   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-5nkdl" "namespace"="test-machine-watches-prt7f" "count"=1
I0726 15:11:54.636096   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-5nkdl" "namespace"="test-machine-watches-prt7f" "descendants"="Worker machines: machine-created-k6tx4" "indirect descendants count"=0
I0726 15:11:54.652086   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-5nkdl" "namespace"="test-machine-watches-prt7f" "count"=1
I0726 15:11:54.652157   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-5nkdl" "namespace"="test-machine-watches-prt7f" "descendants"="Worker machines: machine-created-k6tx4" "indirect descendants count"=0
I0726 15:11:55.512552   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-5nkdl" "machine"="machine-created-k6tx4" "namespace"="test-machine-watches-prt7f" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"7707e25d-15f1-4759-8343-33729d064580","apiVersion":"v1"}
E0726 15:11:55.567087   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-k6tx4\" not found" "controller"="machine" "name"="machine-created-k6tx4" "namespace"="test-machine-watches-prt7f"
E0726 15:11:56.617047   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-twrkb\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-lwwpp\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-lwwpp: secrets \"machine-reconcile-lwwpp-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-twrkb" "namespace"="default"
I0726 15:11:57.617632   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lwwpp" "machine"="machine-created-twrkb" "namespace"="default" "cause"="noderef is nil" "node"=null
I0726 15:11:57.668482   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lwwpp" "machine"="machine-created-twrkb" "namespace"="default" "cause"="noderef is nil" "node"=null
I0726 15:11:57.700714   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lwwpp" "machine"="machine-created-twrkb" "namespace"="default" "cause"="noderef is nil" "node"=null
E0726 15:11:57.737353   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-twrkb\" not found" "controller"="machine" "name"="machine-created-twrkb" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.20s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.20s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 6 lines ...
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0726 15:11:57.752384   10635 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0726 15:11:57.752497   10635 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0726 15:11:57.755649   10635 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0726 15:11:57.755819   10635 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
E0726 15:11:57.756585   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-lwwpp\" not found" "controller"="cluster" "name"="machine-reconcile-lwwpp" "namespace"="default"
--- PASS: TestMachineOwnerReference (0.01s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
... skipping 121 lines ...
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0726 15:11:57.932881   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zx8b6" "namespace"="test-mhc-9z2rd" 
I0726 15:11:57.947985   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
E0726 15:11:58.049726   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9z2rd/test-cluster-lllzx"
E0726 15:11:58.053522   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-zx8b6\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-zx8b6\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-zx8b6" "namespace"="test-mhc-9z2rd"
I0726 15:11:59.054055   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqxnb" "namespace"="test-mhc-m69hm" 
I0726 15:11:59.054171   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lq2s" "namespace"="test-mhc-76jkc" 
I0726 15:11:59.054205   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hb8g6" "namespace"="test-mhc-z7nf9" 
I0726 15:11:59.072066   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:11:59.195649   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zx8b6" "namespace"="test-mhc-9z2rd" 
I0726 15:11:59.195728   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hb8g6" "namespace"="test-mhc-z7nf9" 
I0726 15:11:59.200407   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hb8g6" "namespace"="test-mhc-z7nf9" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0726 15:11:59.261176   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hb8g6" "namespace"="test-mhc-z7nf9" 
E0726 15:11:59.284494   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-z7nf9/test-cluster-p7gmm"
I0726 15:11:59.284988   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsxmh" "namespace"="test-mhc-s84r9" 
E0726 15:11:59.285421   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-p7gmm\" not found" "controller"="cluster" "name"="test-cluster-p7gmm" "namespace"="test-mhc-z7nf9"
I0726 15:11:59.308257   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:11:59.427818   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsxmh" "namespace"="test-mhc-s84r9" 
E0726 15:11:59.491935   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-s84r9/test-cluster-dsqks"
I0726 15:11:59.498560   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsxmh" "namespace"="test-mhc-s84r9" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0726 15:11:59.519719   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
inframachine created: test-mhc-machine-infra-nhjzb
I0726 15:11:59.539488   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-hzm7g
I0726 15:11:59.572442   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.572733   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
I0726 15:11:59.592584   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.593010   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
I0726 15:11:59.599552   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.599983   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
I0726 15:11:59.603501   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.603938   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
I0726 15:11:59.614196   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.614806   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
I0726 15:11:59.633579   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.633911   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
I0726 15:11:59.642685   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.643035   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
node created: test-mhc-node-w5hvj
E0726 15:11:59.644692   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w5hvj, got []"  "node"="test-mhc-node-w5hvj"
E0726 15:11:59.644928   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-w5hvj"
I0726 15:11:59.651126   10635 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx" "noderef"="test-mhc-node-w5hvj"
E0726 15:11:59.656474   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w5hvj, got []"  "node"="test-mhc-node-w5hvj"
E0726 15:11:59.656530   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w5hvj, got []"  "node"="test-mhc-node-w5hvj"
E0726 15:11:59.656483   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-w5hvj"
E0726 15:11:59.656565   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-w5hvj"
I0726 15:11:59.657269   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
inframachine created: test-mhc-machine-infra-brlqm
machine created: test-mhc-machine-8wkp9
I0726 15:11:59.680290   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.681746   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.687497   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
... skipping 72 lines ...
I0726 15:11:59.883892   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.885872   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.889249   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.891108   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.892156   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.893632   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.894064   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-8wkp9/"
I0726 15:11:59.909119   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.909756   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-8wkp9/"
I0726 15:11:59.916526   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.917065   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-8wkp9/"
I0726 15:11:59.938548   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.939384   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-8wkp9/"
I0726 15:11:59.947963   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.948704   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-8wkp9/"
I0726 15:11:59.953346   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.953804   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-8wkp9/"
I0726 15:11:59.976061   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:11:59.976476   10635 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-r6bwx/test-mhc-5rndr/test-mhc-machine-8wkp9/"
E0726 15:11:59.987050   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kglt4, got []"  "node"="test-mhc-node-kglt4"
node created: test-mhc-node-kglt4
E0726 15:11:59.987798   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-kglt4"
I0726 15:11:59.989139   10635 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx" "noderef"="test-mhc-node-kglt4"
E0726 15:12:00.016531   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-kglt4"
E0726 15:12:00.016567   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kglt4, got []"  "node"="test-mhc-node-kglt4"
E0726 15:12:00.016579   10635 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-kglt4"
E0726 15:12:00.016607   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kglt4, got []"  "node"="test-mhc-node-kglt4"
I0726 15:12:00.017345   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
Cleaning up nodes, machines and infra machines.
I0726 15:12:00.047219   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:12:00.054759   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:12:00.055277   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6bwx/test-mhc-5rndr/test-mhc-machine-hzm7g/"
E0726 15:12:00.107113   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-r6bwx/test-cluster-f9z4f"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-sxg8d
machine created: test-mhc-machine-t4sft
E0726 15:12:00.174923   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
E0726 15:12:00.295312   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-5rndr\" not found" "controller"="machinehealthcheck" "name"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx"
E0726 15:12:00.312457   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-prt7f/machine-reconcile-5nkdl"
E0726 15:12:01.189908   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
node created: test-mhc-node-m5ztn
I0726 15:12:01.296130   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
inframachine created: test-mhc-machine-infra-vpbdm
I0726 15:12:01.326502   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0726 15:12:01.326870   10635 machinehealthcheck_controller.go:202] controllers/MachineHealthCheck "msg"="Failed to fetch targets from MachineHealthCheck" "error"="error getting node: the cache is not started, can not read objects" "cluster"="test-cluster-wwvkd" 
E0726 15:12:01.326905   10635 machinehealthcheck_controller.go:167] controllers/MachineHealthCheck "msg"="Failed to reconcile MachineHealthCheck" "error"="error getting node: the cache is not started, can not read objects" "cluster"="test-cluster-wwvkd" 
machine created: test-mhc-machine-cs95r
E0726 15:12:01.340180   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="error getting node: the cache is not started, can not read objects" "controller"="machinehealthcheck" "name"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6"
E0726 15:12:02.190319   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:02.340526   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rndr" "namespace"="test-mhc-r6bwx" 
I0726 15:12:02.340622   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:02.368361   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:02.369564   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:02.371629   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:02.373681   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
... skipping 304 lines ...
I0726 15:12:03.219323   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.221342   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.223736   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.225845   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.226713   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.227832   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
E0726 15:12:03.232555   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:03.233418   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.234790   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.236105   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.239520   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.240863   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:03.245382   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
... skipping 368 lines ...
I0726 15:12:04.238101   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.240224   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.241640   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.242658   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.243704   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.244720   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
E0726 15:12:04.249982   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:04.251074   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.251466   10635 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-t29l6/test-mhc-lnxzs/test-mhc-machine-cs95r/"
I0726 15:12:04.262122   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.262545   10635 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-t29l6/test-mhc-lnxzs/test-mhc-machine-cs95r/"
E0726 15:12:04.265604   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ls5jc, got []"  "node"="test-mhc-node-ls5jc"
node created: test-mhc-node-ls5jc
I0726 15:12:04.274687   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
inframachine created: test-mhc-machine-infra-4tmkm
machine created: test-mhc-machine-l8dj7
I0726 15:12:04.289260   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:04.296506   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
... skipping 322 lines ...
I0726 15:12:05.255862   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.258882   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.262239   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.265669   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.268453   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.269833   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
E0726 15:12:05.271899   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:05.272128   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.275373   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.278719   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.281228   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.283794   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:05.286452   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
... skipping 345 lines ...
I0726 15:12:06.294874   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.296765   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.299534   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.301568   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.303095   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.305121   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
E0726 15:12:06.307613   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:06.309515   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.313396   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.314781   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.317864   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.323184   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:06.325817   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
... skipping 313 lines ...
I0726 15:12:07.308575   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.311108   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.313618   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.315869   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.317244   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.325229   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.326453   10635 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-t29l6/test-mhc-lnxzs/test-mhc-machine-l8dj7/"
E0726 15:12:07.339289   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:07.340346   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.340923   10635 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-t29l6/test-mhc-lnxzs/test-mhc-machine-l8dj7/"
E0726 15:12:07.411493   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5jnkw, got []"  "node"="test-mhc-node-5jnkw"
node created: test-mhc-node-5jnkw
I0726 15:12:07.419315   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.419886   10635 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-t29l6/test-mhc-lnxzs/test-mhc-machine-l8dj7/test-mhc-node-5jnkw"
Cleaning up nodes, machines and infra machines.
I0726 15:12:07.436214   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.436718   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-t29l6/test-mhc-lnxzs/test-mhc-machine-l8dj7/"
Cleaning up nodes, machines and infra machines.
I0726 15:12:07.451311   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:07.452540   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-t29l6/test-mhc-lnxzs/test-mhc-machine-t4sft/"
I0726 15:12:07.483136   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-wwvkd" "namespace"="test-mhc-t29l6" "count"=2
I0726 15:12:07.483235   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-wwvkd" "namespace"="test-mhc-t29l6" "descendants"="Worker machines: test-mhc-machine-l8dj7,test-mhc-machine-t4sft,test-mhc-machine-cs95r" "indirect descendants count"=1
I0726 15:12:07.487672   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-wwvkd" "namespace"="test-mhc-t29l6" "count"=2
I0726 15:12:07.487740   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-wwvkd" "namespace"="test-mhc-t29l6" "descendants"="Worker machines: test-mhc-machine-t4sft,test-mhc-machine-cs95r,test-mhc-machine-l8dj7" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0726 15:12:07.581789   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-t29l6/test-mhc-lnxzs/test-mhc-machine-cs95r/"
I0726 15:12:07.599176   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-t29l6/test-mhc-lnxzs/test-mhc-machine-l8dj7/"
E0726 15:12:07.602855   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-lnxzs\" not found" "controller"="machinehealthcheck" "name"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6"
inframachine created: test-mhc-machine-infra-244pc
machine created: test-mhc-machine-26f2w
I0726 15:12:08.339779   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wwvkd" "machine"="test-mhc-machine-cs95r" "namespace"="test-mhc-t29l6" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ls5jc"}
E0726 15:12:08.389091   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cs95r\" not found" "controller"="machine" "name"="test-mhc-machine-cs95r" "namespace"="test-mhc-t29l6"
I0726 15:12:08.603187   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnxzs" "namespace"="test-mhc-t29l6" 
I0726 15:12:08.603289   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:08.626909   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:12:08.744960   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:08.750296   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:08.771221   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:08.812266   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:08.893409   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:09.054450   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:09.375522   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:09.389477   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:10.016579   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:10.390001   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wwvkd" "machine"="test-mhc-machine-l8dj7" "namespace"="test-mhc-t29l6" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5jnkw"}
E0726 15:12:10.437176   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l8dj7\" not found" "controller"="machine" "name"="test-mhc-machine-l8dj7" "namespace"="test-mhc-t29l6"
I0726 15:12:11.297607   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:11.437580   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:12.443790   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wwvkd" "machine"="test-mhc-machine-t4sft" "namespace"="test-mhc-t29l6" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-m5ztn"}
I0726 15:12:12.487897   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-wwvkd" "namespace"="test-mhc-t29l6" "count"=1
I0726 15:12:12.488081   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-wwvkd" "namespace"="test-mhc-t29l6" "descendants"="Worker machines: test-mhc-machine-t4sft" "indirect descendants count"=0
E0726 15:12:12.499888   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-t4sft\" not found" "controller"="machine" "name"="test-mhc-machine-t4sft" "namespace"="test-mhc-t29l6"
I0726 15:12:13.519132   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.538860   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:13.541713   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
node created: test-mhc-node-9m4pv
E0726 15:12:13.566692   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9m4pv, got []"  "node"="test-mhc-node-9m4pv"
E0726 15:12:13.566902   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9m4pv, got []"  "node"="test-mhc-node-9m4pv"
I0726 15:12:13.569551   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.576600   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
inframachine created: test-mhc-machine-infra-wdp28
machine created: test-mhc-machine-5g2t9
I0726 15:12:13.599273   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.611080   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.616234   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.637554   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.678911   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.760234   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:13.932515   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:14.253965   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:14.542318   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:14.895365   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.555047   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.556869   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.569417   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.601052   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.608566   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.614331   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.619970   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:15.620110   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:15.638697   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:15.709736   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qpzjw, got []"  "node"="test-mhc-node-qpzjw"
E0726 15:12:15.709941   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qpzjw, got []"  "node"="test-mhc-node-qpzjw"
node created: test-mhc-node-qpzjw
I0726 15:12:15.717295   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
inframachine created: test-mhc-machine-infra-dnqsx
machine created: test-mhc-machine-496sw
I0726 15:12:15.737705   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:15.750489   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:16.176838   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:16.620493   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
E0726 15:12:17.501403   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-t29l6/test-cluster-wwvkd"
I0726 15:12:17.631092   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:17.647150   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:17.654830   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:17.669153   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:17.675528   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:17.684476   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:17.688609   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:17.691203   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:17.712361   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
E0726 15:12:17.752427   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mgh46, got []"  "node"="test-mhc-node-mgh46"
node created: test-mhc-node-mgh46
I0726 15:12:17.761893   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
Cleaning up nodes, machines and infra machines.
I0726 15:12:17.774915   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
Cleaning up nodes, machines and infra machines.
I0726 15:12:17.841434   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-tt4d8" "namespace"="test-mhc-cprwf" "count"=2
... skipping 4 lines ...
inframachine created: test-mhc-machine-infra-vpwxj
machine created: test-mhc-machine-7tv8p
I0726 15:12:17.921886   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:17.950378   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:12:17.976410   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2zhg" "namespace"="test-mhc-cprwf" 
I0726 15:12:17.976498   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
E0726 15:12:18.691613   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:19.692170   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tt4d8" "machine"="test-mhc-machine-26f2w" "namespace"="test-mhc-cprwf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9m4pv"}
E0726 15:12:19.738775   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-26f2w\" not found" "controller"="machine" "name"="test-mhc-machine-26f2w" "namespace"="test-mhc-cprwf"
I0726 15:12:20.739430   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tt4d8" "machine"="test-mhc-machine-5g2t9" "namespace"="test-mhc-cprwf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-qpzjw"}
E0726 15:12:20.794716   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5g2t9\" not found" "controller"="machine" "name"="test-mhc-machine-5g2t9" "namespace"="test-mhc-cprwf"
I0726 15:12:21.795336   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tt4d8" "machine"="test-mhc-machine-496sw" "namespace"="test-mhc-cprwf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mgh46"}
E0726 15:12:21.836070   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-496sw\" not found" "controller"="machine" "name"="test-mhc-machine-496sw" "namespace"="test-mhc-cprwf"
I0726 15:12:22.846199   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
E0726 15:12:22.852294   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:22.852403   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
E0726 15:12:22.872524   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-cprwf/test-cluster-tt4d8"
node created: test-mhc-node-9w7xh
E0726 15:12:22.925258   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9w7xh, got []"  "node"="test-mhc-node-9w7xh"
I0726 15:12:22.933257   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
inframachine created: test-mhc-machine-infra-x6l7g
I0726 15:12:22.947537   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:22.950582   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
machine created: test-mhc-machine-9dn9v
I0726 15:12:22.957945   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
E0726 15:12:23.852662   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:24.877530   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:24.885635   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:24.901513   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:24.910413   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:24.920077   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
E0726 15:12:24.924869   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:24.933519   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
node created: test-mhc-node-l592w
E0726 15:12:24.969057   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-l592w, got []"  "node"="test-mhc-node-l592w"
I0726 15:12:24.976579   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
inframachine created: test-mhc-machine-infra-lgpqp
I0726 15:12:24.997222   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:25.000397   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
machine created: test-mhc-machine-kjqwb
I0726 15:12:25.011143   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:25.937352   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:25.953989   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:25.961563   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:25.977736   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:25.991804   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:26.033876   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:26.041956   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
E0726 15:12:26.044602   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
Cleaning up nodes, machines and infra machines.
I0726 15:12:26.116283   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
Cleaning up nodes, machines and infra machines.
I0726 15:12:26.133476   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:26.134570   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zfflw/test-mhc-jgxvx/test-mhc-machine-7tv8p/"
I0726 15:12:26.173719   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cvs6g" "namespace"="test-mhc-zfflw" "count"=2
I0726 15:12:26.173815   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cvs6g" "namespace"="test-mhc-zfflw" "descendants"="Worker machines: test-mhc-machine-7tv8p,test-mhc-machine-9dn9v,test-mhc-machine-kjqwb" "indirect descendants count"=1
I0726 15:12:26.179650   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:26.180478   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zfflw/test-mhc-jgxvx/test-mhc-machine-7tv8p/"
I0726 15:12:26.182608   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zfflw/test-mhc-jgxvx/test-mhc-machine-9dn9v/"
I0726 15:12:26.184052   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cvs6g" "namespace"="test-mhc-zfflw" "count"=2
I0726 15:12:26.184128   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cvs6g" "namespace"="test-mhc-zfflw" "descendants"="Worker machines: test-mhc-machine-7tv8p,test-mhc-machine-9dn9v,test-mhc-machine-kjqwb" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
E0726 15:12:26.217075   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-jgxvx\" not found" "controller"="machinehealthcheck" "name"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw"
inframachine created: test-mhc-machine-infra-dcfxf
machine created: test-mhc-machine-lsk2m
I0726 15:12:27.045193   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cvs6g" "machine"="test-mhc-machine-7tv8p" "namespace"="test-mhc-zfflw" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9w7xh"}
E0726 15:12:27.090231   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7tv8p\" not found" "controller"="machine" "name"="test-mhc-machine-7tv8p" "namespace"="test-mhc-zfflw"
I0726 15:12:27.217365   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jgxvx" "namespace"="test-mhc-zfflw" 
I0726 15:12:27.217487   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:27.230598   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:12:27.349418   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:27.367680   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:27.368743   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
... skipping 333 lines ...
I0726 15:12:28.138873   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.140966   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.142879   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.144730   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.146605   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.148853   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
E0726 15:12:28.150211   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9dn9v\" not found" "controller"="machine" "name"="test-mhc-machine-9dn9v" "namespace"="test-mhc-zfflw"
I0726 15:12:28.150745   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.152610   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.154440   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.156257   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.158171   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:28.160027   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
... skipping 459 lines ...
I0726 15:12:29.181167   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.182904   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.184677   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.190632   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.192523   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.194328   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
E0726 15:12:29.195131   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kjqwb\" not found" "controller"="machine" "name"="test-mhc-machine-kjqwb" "namespace"="test-mhc-zfflw"
I0726 15:12:29.196232   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.198050   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.199891   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.201724   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.203538   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:29.213310   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
... skipping 478 lines ...
I0726 15:12:30.219575   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.221498   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.222734   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.223906   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.225862   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.228992   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
E0726 15:12:30.229486   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:30.229545   10635 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-fd829/test-mhc-vldwq/test-mhc-machine-lsk2m/"
I0726 15:12:30.246128   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.246462   10635 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-fd829/test-mhc-vldwq/test-mhc-machine-lsk2m/"
node created: test-mhc-node-g6xkj
E0726 15:12:30.261860   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g6xkj, got []"  "node"="test-mhc-node-g6xkj"
E0726 15:12:30.263846   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g6xkj, got []"  "node"="test-mhc-node-g6xkj"
I0726 15:12:30.271309   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.293037   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.305506   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.305945   10635 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-fd829/test-mhc-vldwq/test-mhc-machine-lsk2m/test-mhc-node-g6xkj"
I0726 15:12:30.347995   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.349661   10635 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-fd829/test-mhc-vldwq/test-mhc-machine-lsk2m/test-mhc-node-g6xkj"
Cleaning up nodes, machines and infra machines.
I0726 15:12:30.363419   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.364132   10635 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fd829/test-mhc-vldwq/test-mhc-machine-lsk2m/"
I0726 15:12:30.389075   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4kkgk" "namespace"="test-mhc-fd829" "descendants"="Worker machines: test-mhc-machine-lsk2m" "indirect descendants count"=1
I0726 15:12:30.394711   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4kkgk" "namespace"="test-mhc-fd829" "descendants"="Worker machines: test-mhc-machine-lsk2m" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0726 15:12:30.560095   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vldwq" "namespace"="test-mhc-fd829" 
I0726 15:12:30.636773   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" "creating"=1 "need"=1
I0726 15:12:30.636828   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" 
I0726 15:12:30.649814   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-2zc5h-4h2tr\"" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" 
I0726 15:12:30.729292   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:30.743983   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:12:30.877490   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:30.882643   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
E0726 15:12:31.199374   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zfflw/test-cluster-cvs6g"
E0726 15:12:31.229932   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:31.877707   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:32.238204   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4kkgk" "machine"="test-mhc-machine-lsk2m" "namespace"="test-mhc-fd829" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-g6xkj"}
E0726 15:12:32.310702   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lsk2m\" not found" "controller"="machine" "name"="test-mhc-machine-lsk2m" "namespace"="test-mhc-fd829"
I0726 15:12:32.878604   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:33.320509   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:33.321376   10635 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" 
I0726 15:12:33.330322   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:33.330577   10635 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" 
I0726 15:12:33.338719   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
... skipping 5 lines ...
I0726 15:12:33.363189   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:33.363233   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:33.879712   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:34.362476   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:34.362657   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.000687   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.001197   10635 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-8crqm/test-mhc-kf966/mhc-ms-2zc5h-4h2tr/"
I0726 15:12:35.009415   10635 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.013943   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.013994   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.021565   10635 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.030580   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.030947   10635 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-8crqm/test-mhc-kf966/mhc-ms-2zc5h-4h2tr/"
I0726 15:12:35.044388   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.044438   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.092389   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-gsgn7" "namespace"="test-mhc-8crqm" "count"=1
I0726 15:12:35.092453   10635 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-gsgn7" "namespace"="test-mhc-8crqm" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-2zc5h"
I0726 15:12:35.093677   10635 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-2zc5h" "namespace"="test-mhc-8crqm" "machine"="mhc-ms-2zc5h-4h2tr"
I0726 15:12:35.098552   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-gsgn7" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" "cause"="cluster is being deleted" "node"=null
I0726 15:12:35.099979   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.100312   10635 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-8crqm/test-mhc-kf966/mhc-ms-2zc5h-4h2tr/"
I0726 15:12:35.103840   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-gsgn7" "namespace"="test-mhc-8crqm" "descendants"="Machine sets: mhc-ms-2zc5h;Worker machines: mhc-ms-2zc5h-4h2tr" "indirect descendants count"=1
I0726 15:12:35.106833   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kf966" "namespace"="test-mhc-8crqm" 
I0726 15:12:35.113748   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-gsgn7" "namespace"="test-mhc-8crqm" "descendants"="Worker machines: mhc-ms-2zc5h-4h2tr" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0726 15:12:35.149623   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-gsgn7" "machine"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm" "cause"="cluster is being deleted" "node"=null
E0726 15:12:35.218694   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-2zc5h-4h2tr\" not found" "controller"="machine" "name"="mhc-ms-2zc5h-4h2tr" "namespace"="test-mhc-8crqm"
I0726 15:12:35.333464   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
inframachine created: test-mhc-machine-infra-qm999
I0726 15:12:35.351859   10635 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-7lh9l
E0726 15:12:35.461285   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fd829/test-cluster-4kkgk"
I0726 15:12:35.488268   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:35.489464   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:35.491212   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:35.493214   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:35.495422   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:35.497530   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
... skipping 287 lines ...
I0726 15:12:36.193065   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.194959   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.196811   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.205143   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.207092   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.209002   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
E0726 15:12:36.219147   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
I0726 15:12:36.219299   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.221181   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.223083   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.224986   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.226868   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:36.228703   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
... skipping 446 lines ...
I0726 15:12:37.222756   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.224548   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.227049   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.228396   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.229046   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.230741   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
E0726 15:12:37.233419   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
I0726 15:12:37.234168   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.271068   10635 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-7lh9l" "target"="test-mhc-7f9dh/test-mhc-m9lnn/test-mhc-machine-7lh9l/"
node created: test-mhc-node-sw6pk
E0726 15:12:37.279855   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sw6pk, got []"  "node"="test-mhc-node-sw6pk"
E0726 15:12:37.280225   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sw6pk, got []"  "node"="test-mhc-node-sw6pk"
I0726 15:12:37.340978   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.345584   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.387602   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.395122   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.402020   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.410829   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.415849   10635 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-7lh9l" "target"="test-mhc-7f9dh/test-mhc-m9lnn/test-mhc-machine-7lh9l/test-mhc-node-sw6pk"
I0726 15:12:37.438041   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.443791   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
Cleaning up nodes, machines and infra machines.
I0726 15:12:37.448699   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.451247   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
I0726 15:12:37.455697   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m9lnn" "namespace"="test-mhc-7f9dh" 
... skipping 313 lines ...
I0726 15:12:38.276305   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.278334   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.280314   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.282056   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.284088   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.286320   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
E0726 15:12:38.288047   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7lh9l\" not found" "controller"="machine" "name"="test-mhc-machine-7lh9l" "namespace"="test-mhc-7f9dh"
I0726 15:12:38.288222   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.289994   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.291931   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.293739   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.295558   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:38.297417   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
... skipping 496 lines ...
I0726 15:12:39.296053   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.296969   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.297611   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.298134   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.299264   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.301463   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.304485   10635 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-w287r" "target"="test-mhc-tt6c4/test-mhc-gnltx/test-mhc-machine-w287r/"
I0726 15:12:39.316286   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
node created: test-mhc-node-mzcnz
E0726 15:12:39.338524   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mzcnz, got []"  "node"="test-mhc-node-mzcnz"
E0726 15:12:39.338529   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mzcnz, got []"  "node"="test-mhc-node-mzcnz"
E0726 15:12:39.338530   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mzcnz, got []"  "node"="test-mhc-node-mzcnz"
I0726 15:12:39.345851   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.368095   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.400185   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.404762   10635 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-w287r" "target"="test-mhc-tt6c4/test-mhc-gnltx/test-mhc-machine-w287r/test-mhc-node-mzcnz"
I0726 15:12:39.425352   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.434464   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.455444   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
Cleaning up nodes, machines and infra machines.
I0726 15:12:39.458500   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.462390   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.469828   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:39.479589   10635 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-w287r" "target"="test-mhc-tt6c4/test-mhc-gnltx/test-mhc-machine-w287r/"
I0726 15:12:39.485767   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6mgcf" "namespace"="test-mhc-tt6c4" "count"=1
I0726 15:12:39.485858   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6mgcf" "namespace"="test-mhc-tt6c4" "descendants"="Worker machines: test-mhc-machine-w287r" "indirect descendants count"=0
I0726 15:12:39.486624   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6mgcf" "machine"="test-mhc-machine-w287r" "namespace"="test-mhc-tt6c4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mzcnz"}
I0726 15:12:39.489976   10635 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6mgcf" "namespace"="test-mhc-tt6c4" "count"=1
I0726 15:12:39.490079   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6mgcf" "namespace"="test-mhc-tt6c4" "descendants"="Worker machines: test-mhc-machine-w287r" "indirect descendants count"=0
--- PASS: TestMachineHealthCheck_Reconcile (41.60s)
... skipping 15 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 (2.35s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.02s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0726 15:12:39.498334   10635 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
E0726 15:12:39.499990   10635 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
E0726 15:12:39.501745   10635 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0726 15:12:39.501984   10635 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
E0726 15:12:39.502534   10635 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
I0726 15:12:39.505889   10635 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0726 15:12:39.506504   10635 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0726 15:12:39.508402   10635 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
E0726 15:12:39.518558   10635 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
E0726 15:12:39.520437   10635 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1627312298
Will run 16 of 16 specs

E0726 15:12:39.530185   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-w287r\" not found" "controller"="machine" "name"="test-mhc-machine-w287r" "namespace"="test-mhc-tt6c4"
I0726 15:12:39.585075   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0726 15:12:39.585120   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.596433   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-8ztkk-6657c7fddb-fvcd5\"" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.596693   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.609570   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-8ztkk-6657c7fddb-qfqfb\"" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.677038   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0726 15:12:39.677135   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
E0726 15:12:39.685259   10635 machinehealthcheck_controller.go:167] controllers/MachineHealthCheck "msg"="Failed to reconcile MachineHealthCheck" "error"="failed to patch unhealthy machine status for machine: test-mhc-tt6c4/test-mhc-machine-w287r: [Machine.cluster.x-k8s.io \"test-mhc-machine-w287r\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-w287r\" not found]" "cluster"="test-cluster-6mgcf" 
E0726 15:12:39.689055   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[failed to patch unhealthy machine status for machine: test-mhc-tt6c4/test-mhc-machine-w287r: [Machine.cluster.x-k8s.io \"test-mhc-machine-w287r\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-w287r\" not found], machinehealthchecks.cluster.x-k8s.io \"test-mhc-gnltx\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4"
I0726 15:12:39.690025   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-8ztkk-6657c7fddb-z6w8t\"" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.690070   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.701754   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-8ztkk-6657c7fddb-9hbnp\"" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.787911   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:12:39.787972   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.806490   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8ztkk-6657c7fddb-bz7vc\"" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" 
I0726 15:12:39.900235   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0726 15:12:39.900351   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" 
I0726 15:12:39.922948   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8ztkk-cdfc6fd6c-tttm2\"" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" 
E0726 15:12:39.995085   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:39.995087   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:39.995394   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:40.100046   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:40.100084   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:40.100118   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:40.100124   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:40.100134   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:40.100281   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-tttm2-tzdwf, got []"  "node"="md-8ztkk-cdfc6fd6c-tttm2-tzdwf"
E0726 15:12:40.134410   10635 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-8ztkk-cdfc6fd6c-tttm2-tzdwf for machine md-test/md-8ztkk-cdfc6fd6c-tttm2: the cache is not started, can not read objects" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" 
E0726 15:12:40.134742   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8crqm/test-cluster-gsgn7"
I0726 15:12:40.169567   10635 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0726 15:12:40.169672   10635 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0726 15:12:40.177306   10635 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "machine"="md-8ztkk-6657c7fddb-z6w8t"
I0726 15:12:40.207976   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0726 15:12:40.208028   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" 
I0726 15:12:40.223444   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8ztkk-cdfc6fd6c-kzzwz\"" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" 
E0726 15:12:40.341844   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-kzzwz-9z9gx, got []"  "node"="md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"
E0726 15:12:40.341896   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-kzzwz-9z9gx, got []"  "node"="md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"
E0726 15:12:40.345460   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-kzzwz-9z9gx, got []"  "node"="md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"
E0726 15:12:40.345524   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-kzzwz-9z9gx, got []"  "node"="md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"
E0726 15:12:40.345468   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-kzzwz-9z9gx, got []"  "node"="md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"
E0726 15:12:40.345564   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-kzzwz-9z9gx, got []"  "node"="md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"
I0726 15:12:40.388360   10635 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0726 15:12:40.388406   10635 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0726 15:12:40.393419   10635 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "machine"="md-8ztkk-6657c7fddb-9hbnp"
I0726 15:12:40.505896   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:12:40.505955   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" 
I0726 15:12:40.524277   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8ztkk-cdfc6fd6c-nw2j2\"" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" 
I0726 15:12:40.645113   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:40.645157   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
E0726 15:12:40.651136   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-nw2j2-fsscj, got []"  "node"="md-8ztkk-cdfc6fd6c-nw2j2-fsscj"
E0726 15:12:40.651236   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-nw2j2-fsscj, got []"  "node"="md-8ztkk-cdfc6fd6c-nw2j2-fsscj"
I0726 15:12:40.669941   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:12:40.669991   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:12:40.689405   10635 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gnltx" "namespace"="test-mhc-tt6c4" 
I0726 15:12:40.715723   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-bz7vc" "namespace"="md-test" 
I0726 15:12:40.715772   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-bz7vc" "namespace"="md-test" 
E0726 15:12:40.754181   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-nw2j2-fsscj, got []"  "node"="md-8ztkk-cdfc6fd6c-nw2j2-fsscj"
E0726 15:12:40.754221   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-nw2j2-fsscj, got []"  "node"="md-8ztkk-cdfc6fd6c-nw2j2-fsscj"
E0726 15:12:40.754248   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-nw2j2-fsscj, got []"  "node"="md-8ztkk-cdfc6fd6c-nw2j2-fsscj"
E0726 15:12:40.754262   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-cdfc6fd6c-nw2j2-fsscj, got []"  "node"="md-8ztkk-cdfc6fd6c-nw2j2-fsscj"
E0726 15:12:40.777721   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-cdfc6fd6c-tttm2\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-cdfc6fd6c-tttm2" "namespace"="md-test"
I0726 15:12:40.792987   10635 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0726 15:12:40.793033   10635 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0726 15:12:40.799532   10635 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8ztkk-6657c7fddb" "namespace"="md-test" "machine"="md-8ztkk-6657c7fddb-bz7vc"
I0726 15:12:40.967331   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0726 15:12:40.967380   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" 
I0726 15:12:40.981137   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8ztkk-74d45c49c5-vdhqp\"" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" 
E0726 15:12:41.063850   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vdhqp-dj9lw, got []"  "node"="md-8ztkk-74d45c49c5-vdhqp-dj9lw"
E0726 15:12:41.063850   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vdhqp-dj9lw, got []"  "node"="md-8ztkk-74d45c49c5-vdhqp-dj9lw"
E0726 15:12:41.067186   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vdhqp-dj9lw, got []"  "node"="md-8ztkk-74d45c49c5-vdhqp-dj9lw"
E0726 15:12:41.067249   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vdhqp-dj9lw, got []"  "node"="md-8ztkk-74d45c49c5-vdhqp-dj9lw"
E0726 15:12:41.067186   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vdhqp-dj9lw, got []"  "node"="md-8ztkk-74d45c49c5-vdhqp-dj9lw"
E0726 15:12:41.067284   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vdhqp-dj9lw, got []"  "node"="md-8ztkk-74d45c49c5-vdhqp-dj9lw"
I0726 15:12:41.114782   10635 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0726 15:12:41.114820   10635 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0726 15:12:41.118960   10635 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "machine"="md-8ztkk-cdfc6fd6c-kzzwz"
I0726 15:12:41.229806   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0726 15:12:41.229863   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" 
I0726 15:12:41.257789   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8ztkk-74d45c49c5-vk59h\"" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" 
E0726 15:12:41.309144   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vk59h-lcp6f, got []"  "node"="md-8ztkk-74d45c49c5-vk59h-lcp6f"
E0726 15:12:41.309160   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vk59h-lcp6f, got []"  "node"="md-8ztkk-74d45c49c5-vk59h-lcp6f"
E0726 15:12:41.312549   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vk59h-lcp6f, got []"  "node"="md-8ztkk-74d45c49c5-vk59h-lcp6f"
E0726 15:12:41.312624   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vk59h-lcp6f, got []"  "node"="md-8ztkk-74d45c49c5-vk59h-lcp6f"
E0726 15:12:41.312570   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vk59h-lcp6f, got []"  "node"="md-8ztkk-74d45c49c5-vk59h-lcp6f"
E0726 15:12:41.312660   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-vk59h-lcp6f, got []"  "node"="md-8ztkk-74d45c49c5-vk59h-lcp6f"
I0726 15:12:41.356265   10635 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0726 15:12:41.356316   10635 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0726 15:12:41.360271   10635 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8ztkk-cdfc6fd6c" "namespace"="md-test" "machine"="md-8ztkk-cdfc6fd6c-tttm2"
I0726 15:12:41.470207   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:12:41.470264   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" 
I0726 15:12:41.479186   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8ztkk-74d45c49c5-rjl9l\"" "machineset"="md-8ztkk-74d45c49c5" "namespace"="md-test" 
E0726 15:12:41.565271   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-rjl9l-b7qbg, got []"  "node"="md-8ztkk-74d45c49c5-rjl9l-b7qbg"
E0726 15:12:41.565648   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-rjl9l-b7qbg, got []"  "node"="md-8ztkk-74d45c49c5-rjl9l-b7qbg"
E0726 15:12:41.669018   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-rjl9l-b7qbg, got []"  "node"="md-8ztkk-74d45c49c5-rjl9l-b7qbg"
E0726 15:12:41.669092   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-rjl9l-b7qbg, got []"  "node"="md-8ztkk-74d45c49c5-rjl9l-b7qbg"
E0726 15:12:41.669110   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-rjl9l-b7qbg, got []"  "node"="md-8ztkk-74d45c49c5-rjl9l-b7qbg"
E0726 15:12:41.669155   10635 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8ztkk-74d45c49c5-rjl9l-b7qbg, got []"  "node"="md-8ztkk-74d45c49c5-rjl9l-b7qbg"
I0726 15:12:41.701815   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8ztkk-74d45c49c5,md-8ztkk-cdfc6fd6c;Worker machines: md-8ztkk-6657c7fddb-qfqfb,md-8ztkk-cdfc6fd6c-kzzwz,md-8ztkk-6657c7fddb-bz7vc,md-8ztkk-cdfc6fd6c-tttm2,md-8ztkk-74d45c49c5-vdhqp,md-8ztkk-74d45c49c5-rjl9l,md-8ztkk-6657c7fddb-fvcd5,md-8ztkk-74d45c49c5-vk59h,md-8ztkk-cdfc6fd6c-nw2j2" "indirect descendants count"=11
I0726 15:12:41.706397   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8ztkk-74d45c49c5,md-8ztkk-cdfc6fd6c;Worker machines: md-8ztkk-cdfc6fd6c-nw2j2,md-8ztkk-74d45c49c5-vk59h,md-8ztkk-cdfc6fd6c-tttm2,md-8ztkk-74d45c49c5-vdhqp,md-8ztkk-74d45c49c5-rjl9l,md-8ztkk-6657c7fddb-fvcd5,md-8ztkk-6657c7fddb-qfqfb,md-8ztkk-cdfc6fd6c-kzzwz,md-8ztkk-6657c7fddb-bz7vc" "indirect descendants count"=11
E0726 15:12:41.706944   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-8ztkk\" not found" "controller"="machinedeployment" "name"="md-8ztkk" "namespace"="md-test"
•I0726 15:12:41.709476   10635 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"
I0726 15:12:41.711224   10635 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0726 15:12:41.711692   10635 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"
I0726 15:12:41.713265   10635 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0726 15:12:41.713298   10635 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0726 15:12:41.713820   10635 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"
... skipping 16 lines ...
I0726 15:12:41.723398   10635 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"
•I0726 15:12:41.724871   10635 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"
I0726 15:12:41.725556   10635 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"
I0726 15:12:41.726221   10635 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0726 15:12:41.726251   10635 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0726 15:12:41.726761   10635 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0726 15:12:41.728134   10635 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" 
•I0726 15:12:41.778268   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-cdfc6fd6c-kzzwz" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"}
I0726 15:12:41.806945   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-cdfc6fd6c-nw2j2" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8ztkk-cdfc6fd6c-nw2j2-fsscj"}
I0726 15:12:41.836361   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:41.836413   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
•I0726 15:12:41.842059   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:12:41.842107   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:12:41.842843   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-6657c7fddb-bz7vc" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0726 15:12:41.854759   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-gg7gh\" not found" "controller"="cluster" "name"="test1-gg7gh" "namespace"="default"
I0726 15:12:41.877094   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-cdfc6fd6c-tttm2" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8ztkk-cdfc6fd6c-tttm2-tzdwf"}
I0726 15:12:41.940472   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-cdfc6fd6c-kzzwz" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8ztkk-cdfc6fd6c-kzzwz-9z9gx"}
E0726 15:12:41.968088   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8ztkk-cdfc6fd6c-kzzwz\" not found" "controller"="machine" "name"="md-8ztkk-cdfc6fd6c-kzzwz" "namespace"="md-test"
E0726 15:12:42.877902   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7f9dh/test-cluster-987tw"
I0726 15:12:42.968661   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-cdfc6fd6c-nw2j2" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8ztkk-cdfc6fd6c-nw2j2-fsscj"}
•I0726 15:12:42.995514   10635 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-8tktn" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0726 15:12:43.009003   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8ztkk-cdfc6fd6c-nw2j2\" not found" "controller"="machine" "name"="md-8ztkk-cdfc6fd6c-nw2j2" "namespace"="md-test"
I0726 15:12:43.115791   10635 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-8tktn" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0726 15:12:43.119937   10635 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-8tktn" "namespace"="default"
I0726 15:12:44.009555   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-6657c7fddb-bz7vc" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0726 15:12:44.032617   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8ztkk-6657c7fddb-bz7vc\" not found" "controller"="machine" "name"="md-8ztkk-6657c7fddb-bz7vc" "namespace"="md-test"
E0726 15:12:44.135422   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
•I0726 15:12:45.033258   10635 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8ztkk-cdfc6fd6c-tttm2" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8ztkk-cdfc6fd6c-tttm2-tzdwf"}
E0726 15:12:45.059137   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8ztkk-cdfc6fd6c-tttm2\" not found" "controller"="machine" "name"="md-8ztkk-cdfc6fd6c-tttm2" "namespace"="md-test"
E0726 15:12:45.150204   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-79gwc\" not found" "controller"="cluster" "name"="test3-79gwc" "namespace"="default"
E0726 15:12:46.087794   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vdhqp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vdhqp" "namespace"="md-test"
E0726 15:12:46.151020   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
E0726 15:12:47.113727   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vk59h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vk59h" "namespace"="md-test"
E0726 15:12:47.170444   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tt6c4/test-cluster-6mgcf"
E0726 15:12:47.170915   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
•I0726 15:12:48.145742   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:48.145865   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:48.150421   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:12:48.150466   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
E0726 15:12:48.155324   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vdhqp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vdhqp" "namespace"="md-test"
I0726 15:12:48.172276   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8ztkk-74d45c49c5,md-8ztkk-cdfc6fd6c;Worker machines: md-8ztkk-74d45c49c5-vk59h,md-8ztkk-6657c7fddb-fvcd5,md-8ztkk-6657c7fddb-qfqfb,md-8ztkk-74d45c49c5-vdhqp,md-8ztkk-74d45c49c5-rjl9l" "indirect descendants count"=7
E0726 15:12:48.177306   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
E0726 15:12:49.155813   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-hzm7g\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-hzm7g" "namespace"="test-mhc-r6bwx"
E0726 15:12:49.178330   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
E0726 15:12:50.161625   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vk59h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vk59h" "namespace"="md-test"
E0726 15:12:50.195032   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
•E0726 15:12:51.162091   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9z4f\" for machine \"test-mhc-machine-8wkp9\" in namespace \"test-mhc-r6bwx\": Cluster.cluster.x-k8s.io \"test-cluster-f9z4f\" not found" "controller"="machine" "name"="test-mhc-machine-8wkp9" "namespace"="test-mhc-r6bwx"
E0726 15:12:51.195756   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
E0726 15:12:52.171531   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vdhqp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vdhqp" "namespace"="md-test"
E0726 15:12:52.196620   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
I0726 15:12:53.176359   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:53.176421   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:53.180590   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:12:53.180633   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
E0726 15:12:53.184701   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vk59h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vk59h" "namespace"="md-test"
E0726 15:12:53.206196   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
E0726 15:12:54.190004   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vdhqp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vdhqp" "namespace"="md-test"
E0726 15:12:54.206914   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
E0726 15:12:55.195642   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vk59h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vk59h" "namespace"="md-test"
I0726 15:12:55.207592   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8ztkk-cdfc6fd6c,md-8ztkk-74d45c49c5;Worker machines: md-8ztkk-6657c7fddb-fvcd5,md-8ztkk-6657c7fddb-qfqfb,md-8ztkk-74d45c49c5-vdhqp,md-8ztkk-74d45c49c5-rjl9l,md-8ztkk-74d45c49c5-vk59h" "indirect descendants count"=7
E0726 15:12:55.208224   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
E0726 15:12:56.208849   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
I0726 15:12:56.210575   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:56.210629   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:12:56.214977   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:12:56.215020   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
E0726 15:12:56.219497   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vdhqp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vdhqp" "namespace"="md-test"
E0726 15:12:57.209606   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
E0726 15:12:57.224463   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vk59h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vk59h" "namespace"="md-test"
E0726 15:12:58.210325   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
I0726 15:12:58.239027   10635 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-n4wzl" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0726 15:12:58.250140   10635 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-n4wzl" "namespace"="default" 
E0726 15:12:58.264803   10635 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-n4wzl" "namespace"="default"
E0726 15:12:59.211113   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
E0726 15:12:59.270635   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vdhqp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vdhqp" "namespace"="md-test"
E0726 15:13:00.212089   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-8tktn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-8tktn" "namespace"="default"
I0726 15:13:00.275399   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:13:00.275446   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-fvcd5" "namespace"="md-test" 
I0726 15:13:00.279246   10635 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
I0726 15:13:00.279282   10635 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8ztkk-6657c7fddb-qfqfb" "namespace"="md-test" 
E0726 15:13:00.283258   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vk59h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vk59h" "namespace"="md-test"
E0726 15:13:01.212882   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"
I0726 15:13:01.297628   10635 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-n4wzl" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0726 15:13:01.297847   10635 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-n4wzl" "namespace"="default" "noderef"="id-node-1"
E0726 15:13:01.313506   10635 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-n4wzl" "namespace"="default"
I0726 15:13:02.213704   10635 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8ztkk-74d45c49c5,md-8ztkk-cdfc6fd6c;Worker machines: md-8ztkk-74d45c49c5-vk59h,md-8ztkk-6657c7fddb-fvcd5,md-8ztkk-6657c7fddb-qfqfb,md-8ztkk-74d45c49c5-vdhqp,md-8ztkk-74d45c49c5-rjl9l" "indirect descendants count"=7
E0726 15:13:02.218479   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-szjpw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-szjpw" "namespace"="default"

------------------------------
• [SLOW TEST:12.058 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
  /home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:248
------------------------------
E0726 15:13:02.318779   10635 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8ztkk-74d45c49c5-vdhqp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8ztkk-74d45c49c5-vdhqp" "namespace"="md-test"
I0726 15:13:02.372685   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-xmhsk" "namespace"="ms-test" "creating"=2 "need"=2
I0726 15:13:02.372729   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-xmhsk" "namespace"="ms-test" 
I0726 15:13:02.385949   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-xmhsk-nzrwp\"" "machineset"="ms-xmhsk" "namespace"="ms-test" 
I0726 15:13:02.386023   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-xmhsk" "namespace"="ms-test" 
I0726 15:13:02.399051   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-xmhsk-4wszb\"" "machineset"="ms-xmhsk" "namespace"="ms-test" 
I0726 15:13:02.497824   10635 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-xmhsk" "namespace"="ms-test" "creating"=1 "need"=2
I0726 15:13:02.497865   10635 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-xmhsk" "namespace"="ms-test" 
I0726 15:13:02.514173   10635 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-xmhsk-blj2m\"" "machineset"="ms-xmhsk" "namespace"="ms-test" 
E0726 15:13:02.739434   10635 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-xmhsk-blj2m-dllbb for machine ms-test/ms-xmhsk-blj2m: the cache is not started, can not read objects" "machineset"="ms-xmhsk" "namespace"="ms-test" 
E0726 15:13:02.883910   10635 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•

Ran 16 of 16 Specs in 23.364 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (23.36s)
PASS
Tearing down test suite
I0726 15:13:02.886755   10635 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0726 15:13:02.886802   10635 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0726 15:13:02.886851   10635 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0726 15:13:02.886888   10635 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0726 15:13:02.886910   10635 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:13:02.886931   10635 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:13:02.886973   10635 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:13:02.918321   10635 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:45601/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1284&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:45601: connect: connection refused
E0726 15:13:02.918321   10635 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:45601/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1284&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:45601: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	84.125s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0726 15:11:57.765184   11177 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:11:57.776449   11177 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":{}}}
I0726 15:11:57.889196   11177 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0726 15:11:57.889272   11177 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0726 15:11:57.922091   11177 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0726 15:11:58.352868   11177 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0726 15:12:00.379413   11177 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-s8cwt/test-cluster"
•E0726 15:12:00.824522   11177 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-fsbr7/test-cluster"
•E0726 15:12:01.455661   11177 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:38621/?timeout=50ms: dial tcp 127.0.0.1:38621: connect: connection refused"  "cluster"="cluster-cache-test-pk68q/test-cluster"
•E0726 15:12:01.665330   11177 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:12:01.665402   11177 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-104572773/tls.crt: no such file or directory"  
I0726 15:12:01.665455   11177 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:12:01.723530   11177 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:36957/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:36957: connect: connection refused


Ran 5 of 5 Specs in 20.173 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (20.17s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	20.341s
?   	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
I0726 15:12:04.926140   11801 controller.go:133]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0726 15:12:04.927489   11801 controller.go:129]  "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
I0726 15:12:04.928135   11801 controller.go:139]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0726 15:12:04.928347   11801 controller.go:139]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
--- FAIL: TestReconcileClusterNoEndpoints (0.00s)
    controller_test.go:427: 
        Unexpected error:
            <*errors.withStack | 0xc000b12020>: {
                error: {
                    cause: {
                        error: {
                            cause: {
                                ErrStatus: {
                                    TypeMeta: {Kind: "", APIVersion: ""},
                                    ListMeta: {
                                        SelfLink: "",
                                        ResourceVersion: "",
... skipping 11 lines ...
                                        Causes: nil,
                                        RetryAfterSeconds: 0,
                                    },
                                    Code: 404,
                                },
                            },
                            msg: "failed to retrieve kubeconfig secret for Cluster test/foo",
                        },
                        stack: [0x1464401, 0x1734009, 0x172d97f, 0x174564c, 0x50fb29, 0x461751],
                    },
                    msg: "failed to create metadata only client",
                },
                stack: [0x172dc2b, 0x174564c, 0x50fb29, 0x461751],
            }
            failed to create metadata only client: failed to retrieve kubeconfig secret for Cluster test/foo: secrets "foo-kubeconfig" not found
        occurred
=== RUN   TestKubeadmControlPlaneReconciler_adoption
=== RUN   TestKubeadmControlPlaneReconciler_adoption/adopts_existing_Machines
I0726 15:12:04.933210   11801 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-9ys8ln" "kubeadmControlPlane"="kcp-foo-9ys8ln" "namespace"="test" 
=== RUN   TestKubeadmControlPlaneReconciler_adoption/adopts_v1alpha2_cluster_secrets
I0726 15:12:08.996487   11801 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-26s7yv" "kubeadmControlPlane"="kcp-foo-26s7yv" "namespace"="test" 
... skipping 4 lines ...
--- PASS: TestKubeadmControlPlaneReconciler_adoption (11.95s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/adopts_existing_Machines (4.06s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/adopts_v1alpha2_cluster_secrets (1.56s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/Deleted_KubeadmControlPlanes_don't_adopt_machines (2.24s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/refuses_to_adopt_Machines_that_are_more_than_one_version_old (4.09s)
=== RUN   TestReconcileInitializeControlPlane
--- FAIL: TestReconcileInitializeControlPlane (0.00s)
    controller_test.go:897: 
        Unexpected error:
            <*errors.withStack | 0xc000f46840>: {
                error: {
                    cause: {
                        error: {
                            cause: {
                                ErrStatus: {
                                    TypeMeta: {Kind: "", APIVersion: ""},
                                    ListMeta: {
                                        SelfLink: "",
                                        ResourceVersion: "",
... skipping 11 lines ...
                                        Causes: nil,
                                        RetryAfterSeconds: 0,
                                    },
                                    Code: 404,
                                },
                            },
                            msg: "failed to retrieve kubeconfig secret for Cluster test/foo",
                        },
                        stack: [0x1464401, 0x1734009, 0x172d97f, 0x174838b, 0x50fb29, 0x461751],
                    },
                    msg: "failed to create metadata only client",
                },
                stack: [0x172dc2b, 0x174838b, 0x50fb29, 0x461751],
            }
            failed to create metadata only client: failed to retrieve kubeconfig secret for Cluster test/foo: secrets "foo-kubeconfig" not found
        occurred
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/updates_configmaps_and_deployments_successfully
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/returns_no_error_when_no_ClusterConfiguration_is_specified
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/should_not_return_an_error_when_there_is_no_CoreDNS_configmap
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/should_not_return_an_error_when_there_is_no_CoreDNS_deployment
... skipping 178 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
I0726 15:12:20.762468   11801 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
I0726 15:12:20.762607   11801 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: 1627312311
Will run 1 of 1 specs

E0726 15:12:20.795635   11801 controller.go:129]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-0pskyq\" not found" "kubeadmControlPlane"="kcp-foo-0pskyq" "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
I0726 15:12:20.797271   11801 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-v9i0up" "kubeadmControlPlane"="kcp-foo-v9i0up" "namespace"="test" 
I0726 15:12:24.299170   11801 controller.go:348]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-v9i0up" "kubeadmControlPlane"="kcp-foo-v9i0up" "namespace"="test" "needRollout"=["kcp-foo-v9i0up-dghqt"]
I0726 15:12:24.299317   11801 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-v9i0up" "kubeadmControlPlane"="kcp-foo-v9i0up" "namespace"="test" "failures"="[machine kcp-foo-v9i0up-bwnmx does not have APIServerPodHealthy condition, machine kcp-foo-v9i0up-bwnmx does not have ControllerManagerPodHealthy condition, machine kcp-foo-v9i0up-bwnmx does not have SchedulerPodHealthy condition, machine kcp-foo-v9i0up-bwnmx does not have EtcdPodHealthy condition, machine kcp-foo-v9i0up-bwnmx does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (3.50s)
FAIL
I0726 15:12:24.300191   11801 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:12:24.300245   11801 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0726 15:12:24.300338   11801 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-905178706/tls.crt: no such file or directory"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	32.893s
I0726 15:12:02.748330   11755 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:12:02.748463   11755 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:12:02.748494   11755 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:12:02.748530   11755 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:12:02.748669   11755 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
I0726 15:12:02.748812   11755 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1627312310
Will run 7 of 7 specs

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

•••••••
Ran 7 of 7 Specs in 0.002 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
E0726 15:12:06.724750   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:12:15.047834   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:12:24.033871   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:12:35.164155   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:12:51.637297   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:13:04.645832   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:13:22.293365   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:13:43.216793   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:14:14.233409   11755 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:14:59.390706   11755 workload_cluster.go:325]  "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 71 lines ...
=== RUN   TestClusterStatus/returns_cluster_status
=== RUN   TestClusterStatus/returns_cluster_status_with_kubeadm_config
--- PASS: TestClusterStatus (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status_with_kubeadm_config (0.00s)
PASS
E0726 15:14:59.398961   11755 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:14:59.399024   11755 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-571544100/tls.crt: no such file or directory"  
E0726 15:14:59.399045   11755 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:14:59.399063   11755 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-571544100/tls.crt: no such file or directory"  
I0726 15:14:59.399254   11755 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.849s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0726 15:12:14.981499   12009 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0726 15:12:14.981750   12009 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0726 15:12:15.082165   12009 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0726 15:12:15.182589   12009 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0726 15:12:15.182660   12009 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0726 15:12:15.274298   12009 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-xg3igk"} 
E0726 15:12:15.307090   12009 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"
•I0726 15:12:16.361508   12009 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-z0m8ep"} 
E0726 15:12:16.424194   12009 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"
•E0726 15:12:17.481368   12009 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"
•E0726 15:12:18.505770   12009 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"
E0726 15:12:19.664129   12009 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"
•E0726 15:12:20.705031   12009 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"
•E0726 15:12:21.722382   12009 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:12:21.722451   12009 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-872281918/tls.crt: no such file or directory"  
E0726 15:12:21.722473   12009 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:12:21.722493   12009 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-872281918/tls.crt: no such file or directory"  
I0726 15:12:21.722698   12009 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0726 15:12:21.722787   12009 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0726 15:12:21.722853   12009 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:12:21.724991   12009 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"


Ran 5 of 5 Specs in 20.261 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.26s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	20.351s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0726 15:12:08.906989   12411 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
•I0726 15:12:20.270656   12411 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0726 15:12:20.273714   12411 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0726 15:12:20.275042   12411 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


Ran 9 of 9 Specs in 11.350 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.35s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.504s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 204 lines ...
I0726 15:12:45.306638   15211 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=42833
I0726 15:12:45.306715   15211 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I0726 15:12:46.406253   15211 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 14 of 14 Specs in 8.513 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (8.51s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
... skipping 105 lines ...
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#01 (0.00s)
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#02 (0.00s)
=== RUN   TestFromUnstructured
--- PASS: TestFromUnstructured (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/yaml	0.047s
FAIL
make: *** [Makefile:116: test] Error 1
+ EXIT_VALUE=2
+ set +o xtrace