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

No Test Failures!


Error lines from build-log.txt

... skipping 774 lines ...
I0626 14:47:01.785204    8401 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0626 14:47:01.786125    8401 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0626 14:47:01.786422    8401 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=41433
I0626 14:47:01.786680    8401 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0626 14:47:02.430893    8401 kubeadmconfig_controller.go:223]  "msg"="Cluster infrastructure is not ready, waiting" "kind"="Machine" "kubeadmconfig"={"Namespace":"default","Name":"my-machine-config"} "name"="my-machine" "version"="109" 
•I0626 14:47:02.448315    8401 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0626 14:47:02.448401    8401 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0626 14:47:02.448445    8401 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-872993848/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 13.721 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.72s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	46.706s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1406 lines ...
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0626 14:46:45.664877   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
I0626 14:46:45.667954   10454 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
I0626 14:46:45.668371   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
2022/06/26 14:46:45 http: TLS handshake error from 127.0.0.1:43092: EOF
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_is_marked_ready_on_cluster
I0626 14:46:45.671003   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_infrastructure_has_the_paused_annotation
I0626 14:46:45.672202   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig/cluster_not_provisioned,_apiEndpoint_is_not_set
... skipping 97 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0626 14:46:45.717682   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed
I0626 14:46:45.719980   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0626 14:46:45.720368   10454 machine_controller_phases.go:246]  "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-test\" in namespace \"default\", requeuing: requeue in 1s"  
=== RUN   TestReconcileInfrastructure/infrastructure_ref_is_paused
I0626 14:46:45.720969   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0626 14:46:45.893852   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0626 14:46:45.896534   10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0626 14:46:45.908569   10454 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0626 14:46:45.908658   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0626 14:46:46.021178   10454 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0626 14:46:46.021259   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0626 14:46:46.121705   10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "noderef"="node-1"
E0626 14:46:46.129503   10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0626 14:46:46.129558   10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0626 14:46:46.165963   10454 machine_controller_phases.go:246] controllers/Machine "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-created-78258\" in namespace \"test-machine-watches-mwchl\", requeuing: requeue in 1s"  
E0626 14:46:46.175975   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-created-78258\" in namespace \"test-machine-watches-mwchl\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-78258\" in namespace \"test-machine-watches-mwchl\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-78258" "namespace"="test-machine-watches-mwchl"
--- PASS: TestWatches (0.53s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I0626 14:46:46.445520   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "count"=1
I0626 14:46:46.445592   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "descendants"="Worker machines: machine-created-78258" "indirect descendants count"=0
I0626 14:46:46.459411   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "count"=1
I0626 14:46:46.459464   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-kptkq" "namespace"="test-machine-watches-mwchl" "descendants"="Worker machines: machine-created-78258" "indirect descendants count"=0
I0626 14:46:47.176474   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-kptkq" "machine"="machine-created-78258" "namespace"="test-machine-watches-mwchl" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"78ca5071-5d20-4ffd-b5ff-7472625fe2ad","apiVersion":"v1"}
E0626 14:46:47.216950   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-78258\" not found" "controller"="machine" "name"="machine-created-78258" "namespace"="test-machine-watches-mwchl"
E0626 14:46:48.331380   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-q8649\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-h6g5h\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-h6g5h: secrets \"machine-reconcile-h6g5h-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-q8649" "namespace"="default"
I0626 14:46:49.331852   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-h6g5h" "machine"="machine-created-q8649" "namespace"="default" "cause"="noderef is nil" "node"=null
I0626 14:46:49.356788   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-h6g5h" "machine"="machine-created-q8649" "namespace"="default" "cause"="noderef is nil" "node"=null
I0626 14:46:49.396009   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-h6g5h" "machine"="machine-created-q8649" "namespace"="default" "cause"="noderef is nil" "node"=null
E0626 14:46:49.420865   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-q8649\" not found" "controller"="machine" "name"="machine-created-q8649" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.18s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.18s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 17 lines ...
=== RUN   TestReconcileRequest/machine_should_be_created
I0626 14:46:49.457108   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0626 14:46:49.461721   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0626 14:46:49.466016   10454 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
E0626 14:46:49.471037   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-h6g5h\" not found" "controller"="cluster" "name"="machine-reconcile-h6g5h" "namespace"="default"
--- PASS: TestReconcileRequest (0.02s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.00s)
    --- PASS: TestReconcileRequest/machine_should_be_updated (0.00s)
    --- PASS: TestReconcileRequest/machine_should_be_deleted (0.01s)
=== RUN   TestMachineConditions
=== RUN   TestMachineConditions/all_conditions_true
... skipping 108 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0626 14:46:49.570466   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b9pjk" "namespace"="test-mhc-qv85q" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0626 14:46:49.612583   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0626 14:46:49.613697   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-xxts6\" not found"  "cluster"="test-mhc-qv85q/test-cluster-xxts6"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E0626 14:46:49.634473   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-b9pjk\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-b9pjk\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-b9pjk" "namespace"="test-mhc-qv85q"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0626 14:46:50.642211   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9kt78" "namespace"="test-mhc-v5vgj" 
I0626 14:46:50.642307   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b9pjk" "namespace"="test-mhc-qv85q" 
I0626 14:46:50.642339   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-42mgd" "namespace"="test-mhc-jhmhj" 
I0626 14:46:50.642369   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dkcxw" "namespace"="test-mhc-47l7r" 
I0626 14:46:50.669174   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0626 14:46:50.688074   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dkcxw" "namespace"="test-mhc-47l7r" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0626 14:46:50.700335   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dkcxw" "namespace"="test-mhc-47l7r" 
E0626 14:46:50.711210   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-zs2mb\" not found" "controller"="cluster" "name"="test-cluster-zs2mb" "namespace"="test-mhc-47l7r"
E0626 14:46:50.711559   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-47l7r/test-cluster-zs2mb"
I0626 14:46:50.840277   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbkcd" "namespace"="test-mhc-9bdtx" 
I0626 14:46:50.891463   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0626 14:46:50.916201   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbkcd" "namespace"="test-mhc-9bdtx" 
E0626 14:46:50.943245   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9bdtx/test-cluster-jb2mb"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0626 14:46:50.946400   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbkcd" "namespace"="test-mhc-9bdtx" 
I0626 14:46:50.962418   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
inframachine created: test-mhc-machine-infra-dk4dc
I0626 14:46:50.983217   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-dwh4p
I0626 14:46:51.005889   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.012246   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.012548   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/"
I0626 14:46:51.029270   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.029555   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/"
I0626 14:46:51.039811   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.040131   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/"
I0626 14:46:51.074845   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.075177   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/"
I0626 14:46:51.092181   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.092578   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/"
E0626 14:46:51.101996   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cj949, got []"  "node"="test-mhc-node-cj949"
node created: test-mhc-node-cj949
E0626 14:46:51.102441   10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-cj949"
I0626 14:46:51.103021   10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc" "noderef"="test-mhc-node-cj949"
E0626 14:46:51.107438   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cj949, got []"  "node"="test-mhc-node-cj949"
E0626 14:46:51.107485   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cj949, got []"  "node"="test-mhc-node-cj949"
E0626 14:46:51.107834   10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-cj949"
E0626 14:46:51.107876   10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-cj949"
I0626 14:46:51.115580   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
inframachine created: test-mhc-machine-infra-bkm2k
machine created: test-mhc-machine-ls8zp
I0626 14:46:51.141380   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.146641   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.147834   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
... skipping 98 lines ...
I0626 14:46:51.375888   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.377973   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.380035   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.382146   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.386733   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.388545   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.388985   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-ls8zp/"
E0626 14:46:51.459052   10454 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-25xz4"
E0626 14:46:51.459157   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-25xz4, got []"  "node"="test-mhc-node-25xz4"
node created: test-mhc-node-25xz4
I0626 14:46:51.496520   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.496998   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-ls8zp/"
I0626 14:46:51.500504   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.512001   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
Cleaning up nodes, machines and infra machines.
I0626 14:46:51.524090   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.527316   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.527691   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/"
I0626 14:46:51.546050   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:51.546607   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-dwh4p/"
I0626 14:46:51.547099   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-brccc/test-mhc-z4dtq/test-mhc-machine-ls8zp/"
E0626 14:46:51.603805   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-brccc/test-cluster-mj26m"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0626 14:46:51.613722   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="nodes \"test-mhc-node-25xz4\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
E0626 14:46:51.727797   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-mwchl/machine-reconcile-kptkq"
inframachine created: test-mhc-machine-infra-hg7p4
machine created: test-mhc-machine-r2jgx
E0626 14:46:51.787654   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-z4dtq\" not found" "controller"="machinehealthcheck" "name"="test-mhc-z4dtq" "namespace"="test-mhc-brccc"
E0626 14:46:52.614069   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:46:52.787969   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:52.813058   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0626 14:46:52.830575   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4dtq" "namespace"="test-mhc-brccc" 
I0626 14:46:52.830640   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:52.831641   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:52.833491   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
... skipping 374 lines ...
I0626 14:46:53.609476   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.611179   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.612864   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.614615   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.616282   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.617912   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
E0626 14:46:53.618670   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:46:53.619556   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.621149   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.622829   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.630225   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.631989   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:53.633678   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
... skipping 492 lines ...
I0626 14:46:54.613874   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:54.616307   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:54.618197   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:54.619915   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:54.621718   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:54.623551   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
E0626 14:46:54.629694   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:46:54.630614   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:54.631120   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-r2jgx/"
I0626 14:46:54.640360   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:54.640624   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-r2jgx/"
E0626 14:46:54.704144   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jcbhl, got []"  "node"="test-mhc-node-jcbhl"
node created: test-mhc-node-jcbhl
I0626 14:46:54.711461   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
inframachine created: test-mhc-machine-infra-gclng
I0626 14:46:54.729089   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
machine created: test-mhc-machine-wd58t
I0626 14:46:54.737130   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
... skipping 356 lines ...
I0626 14:46:55.620130   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.622039   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.623973   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.625892   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.627826   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.629864   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
E0626 14:46:55.630282   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:46:55.631920   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.633821   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.635783   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.637733   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.639717   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:55.641610   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
... skipping 446 lines ...
I0626 14:46:56.662742   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.664253   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.665184   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.666253   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.667315   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.669571   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
E0626 14:46:56.674449   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:46:56.674566   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.675864   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.678894   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.689292   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.691432   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:56.693530   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
... skipping 372 lines ...
I0626 14:46:57.679355   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.681454   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.683616   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.684686   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.685687   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.687833   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
E0626 14:46:57.688333   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:46:57.688964   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.689289   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-wd58t/"
I0626 14:46:57.708303   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.708707   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-wd58t/"
E0626 14:46:57.761303   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5hzdg, got []"  "node"="test-mhc-node-5hzdg"
node created: test-mhc-node-5hzdg
I0626 14:46:57.767843   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
inframachine created: test-mhc-machine-infra-zxb6l
I0626 14:46:57.783084   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:57.786451   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
machine created: test-mhc-machine-f5bvk
... skipping 328 lines ...
I0626 14:46:58.706458   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.709360   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.718202   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.720852   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.723141   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.725371   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
E0626 14:46:58.725677   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:46:58.727836   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.729094   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.730318   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.731560   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.732731   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:58.733936   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
... skipping 336 lines ...
I0626 14:46:59.757444   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.759029   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.761383   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.762985   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.765029   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.769641   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
E0626 14:46:59.773284   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:46:59.779052   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.780774   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.782488   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.787311   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.789804   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:46:59.793978   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
... skipping 309 lines ...
I0626 14:47:00.779378   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.782213   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.784651   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.787300   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.790660   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.792049   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.792441   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/"
I0626 14:47:00.800966   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.801398   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/"
E0626 14:47:00.810077   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
node created: test-mhc-node-zjmr4
E0626 14:47:00.829426   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zjmr4, got []"  "node"="test-mhc-node-zjmr4"
Cleaning up nodes, machines and infra machines.
I0626 14:47:00.843104   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.843798   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/test-mhc-node-zjmr4"
I0626 14:47:00.855381   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.855824   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/"
Cleaning up nodes, machines and infra machines.
I0626 14:47:00.864746   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.865244   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/"
I0626 14:47:00.866501   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:00.866900   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-r2jgx/"
I0626 14:47:00.894423   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "count"=2
I0626 14:47:00.894498   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "descendants"="Worker machines: test-mhc-machine-r2jgx,test-mhc-machine-wd58t,test-mhc-machine-f5bvk" "indirect descendants count"=1
I0626 14:47:00.897975   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "count"=2
I0626 14:47:00.898033   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qgnf6" "namespace"="test-mhc-hhpfd" "descendants"="Worker machines: test-mhc-machine-r2jgx,test-mhc-machine-wd58t,test-mhc-machine-f5bvk" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
inframachine created: test-mhc-machine-infra-qwqkx
machine created: test-mhc-machine-5mjxw
I0626 14:47:01.061798   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hhpfd/test-mhc-94th7/test-mhc-machine-f5bvk/"
E0626 14:47:01.064622   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-94th7\" not found" "controller"="machinehealthcheck" "name"="test-mhc-94th7" "namespace"="test-mhc-hhpfd"
I0626 14:47:01.811469   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qgnf6" "machine"="test-mhc-machine-wd58t" "namespace"="test-mhc-hhpfd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5hzdg"}
E0626 14:47:01.845329   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wd58t\" not found" "controller"="machine" "name"="test-mhc-machine-wd58t" "namespace"="test-mhc-hhpfd"
I0626 14:47:02.064898   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:02.079671   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0626 14:47:02.195509   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-94th7" "namespace"="test-mhc-hhpfd" 
I0626 14:47:02.195569   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:02.199999   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:02.200535   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:02.241188   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:02.322172   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:02.483188   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:02.806279   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
E0626 14:47:02.846326   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:47:03.449387   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:03.846788   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qgnf6" "machine"="test-mhc-machine-f5bvk" "namespace"="test-mhc-hhpfd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zjmr4"}
E0626 14:47:03.885401   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f5bvk\" not found" "controller"="machine" "name"="test-mhc-machine-f5bvk" "namespace"="test-mhc-hhpfd"
I0626 14:47:04.730452   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:04.886485   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qgnf6" "machine"="test-mhc-machine-r2jgx" "namespace"="test-mhc-hhpfd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jcbhl"}
E0626 14:47:04.938038   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-r2jgx\" not found" "controller"="machine" "name"="test-mhc-machine-r2jgx" "namespace"="test-mhc-hhpfd"
E0626 14:47:05.907860   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hhpfd/test-cluster-qgnf6"
E0626 14:47:05.938486   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:06.948857   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
E0626 14:47:06.973165   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:47:06.973195   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
node created: test-mhc-node-zltf8
E0626 14:47:07.017470   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zltf8, got []"  "node"="test-mhc-node-zltf8"
inframachine created: test-mhc-machine-infra-9jl62
I0626 14:47:07.037389   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
machine created: test-mhc-machine-drrpg
I0626 14:47:07.053828   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:07.231073   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:07.236189   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:07.257271   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:07.298382   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:07.379590   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:07.540599   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:07.861929   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
E0626 14:47:07.973558   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:08.503242   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:08.985360   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:08.991626   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:09.000795   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:09.004634   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:09.011951   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
E0626 14:47:09.018681   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:47:09.018688   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:09.043977   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
E0626 14:47:09.058377   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ssxjb, got []"  "node"="test-mhc-node-ssxjb"
node created: test-mhc-node-ssxjb
I0626 14:47:09.067474   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
inframachine created: test-mhc-machine-infra-c7bgm
I0626 14:47:09.076966   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:09.085011   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
machine created: test-mhc-machine-29xs6
I0626 14:47:09.095276   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:09.102090   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:09.784821   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
E0626 14:47:10.019031   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:11.032626   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.059748   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.065525   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.075388   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.086934   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.093998   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
E0626 14:47:11.097628   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:47:11.098781   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.126262   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
node created: test-mhc-node-vkbvv
E0626 14:47:11.202995   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vkbvv, got []"  "node"="test-mhc-node-vkbvv"
Cleaning up nodes, machines and infra machines.
I0626 14:47:11.208822   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.219347   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
Cleaning up nodes, machines and infra machines.
I0626 14:47:11.250438   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9rv2z" "namespace"="test-mhc-9brkx" "count"=2
I0626 14:47:11.250536   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9rv2z" "namespace"="test-mhc-9brkx" "descendants"="Worker machines: test-mhc-machine-5mjxw,test-mhc-machine-drrpg,test-mhc-machine-29xs6" "indirect descendants count"=1
... skipping 3 lines ...
inframachine created: test-mhc-machine-infra-r8x5q
machine created: test-mhc-machine-5mbrg
I0626 14:47:11.441439   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:11.459574   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0626 14:47:11.576761   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68bqm" "namespace"="test-mhc-9brkx" 
I0626 14:47:11.576826   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
E0626 14:47:12.097935   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:13.098433   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9rv2z" "machine"="test-mhc-machine-5mjxw" "namespace"="test-mhc-9brkx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zltf8"}
E0626 14:47:13.132328   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5mjxw\" not found" "controller"="machine" "name"="test-mhc-machine-5mjxw" "namespace"="test-mhc-9brkx"
I0626 14:47:14.132925   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9rv2z" "machine"="test-mhc-machine-drrpg" "namespace"="test-mhc-9brkx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ssxjb"}
E0626 14:47:14.173399   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-drrpg\" not found" "controller"="machine" "name"="test-mhc-machine-drrpg" "namespace"="test-mhc-9brkx"
I0626 14:47:15.173843   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9rv2z" "machine"="test-mhc-machine-29xs6" "namespace"="test-mhc-9brkx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vkbvv"}
E0626 14:47:15.219686   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-29xs6\" not found" "controller"="machine" "name"="test-mhc-machine-29xs6" "namespace"="test-mhc-9brkx"
I0626 14:47:16.227778   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
E0626 14:47:16.233425   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:47:16.233634   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
E0626 14:47:16.268495   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9brkx/test-cluster-9rv2z"
E0626 14:47:16.311377   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-s28fj, got []"  "node"="test-mhc-node-s28fj"
node created: test-mhc-node-s28fj
I0626 14:47:16.318946   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
inframachine created: test-mhc-machine-infra-vdc5x
I0626 14:47:16.334071   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:16.343109   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
machine created: test-mhc-machine-9x9j5
I0626 14:47:16.349756   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
E0626 14:47:17.233822   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:18.247351   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.254359   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.263166   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.271531   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.280942   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.285870   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.301284   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.317771   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.362496   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
E0626 14:47:18.363232   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-npzd6, got []"  "node"="test-mhc-node-npzd6"
node created: test-mhc-node-npzd6
I0626 14:47:18.426737   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.430974   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
inframachine created: test-mhc-machine-infra-qnktr
I0626 14:47:18.455897   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
machine created: test-mhc-machine-qmb7p
... skipping 7 lines ...
Cleaning up nodes, machines and infra machines.
I0626 14:47:18.566596   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fmhjl" "machine"="test-mhc-machine-qmb7p" "namespace"="test-mhc-4g4s6" "cause"="noderef is nil" "node"=null
I0626 14:47:18.567778   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.573140   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
Cleaning up nodes, machines and infra machines.
I0626 14:47:18.610230   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.610840   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-5mbrg/"
I0626 14:47:18.644364   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.645102   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-5mbrg/"
I0626 14:47:18.645441   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-9x9j5/"
E0626 14:47:18.656074   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qmb7p\" not found" "controller"="machine" "name"="test-mhc-machine-qmb7p" "namespace"="test-mhc-4g4s6"
I0626 14:47:18.666592   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
I0626 14:47:18.667236   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-5mbrg/"
I0626 14:47:18.667649   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4g4s6/test-mhc-lhs8w/test-mhc-machine-9x9j5/"
I0626 14:47:18.668720   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "count"=2
I0626 14:47:18.668791   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "descendants"="Worker machines: test-mhc-machine-5mbrg,test-mhc-machine-9x9j5" "indirect descendants count"=0
I0626 14:47:18.673468   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "count"=2
I0626 14:47:18.673525   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fmhjl" "namespace"="test-mhc-4g4s6" "descendants"="Worker machines: test-mhc-machine-5mbrg,test-mhc-machine-9x9j5" "indirect descendants count"=0
I0626 14:47:18.676622   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lhs8w" "namespace"="test-mhc-4g4s6" 
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
... skipping 460 lines ...
I0626 14:47:19.708359   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.709947   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.711719   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.713703   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.715290   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.716906   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
E0626 14:47:19.717846   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5mbrg\" not found" "controller"="machine" "name"="test-mhc-machine-5mbrg" "namespace"="test-mhc-4g4s6"
I0626 14:47:19.718493   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.720189   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.721839   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.723448   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.725047   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:19.726759   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
... skipping 513 lines ...
I0626 14:47:20.755221   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.756910   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.758617   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.760216   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.761814   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.763780   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
E0626 14:47:20.764675   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9x9j5\" not found" "controller"="machine" "name"="test-mhc-machine-9x9j5" "namespace"="test-mhc-4g4s6"
I0626 14:47:20.765504   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.767437   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.769155   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.770872   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.772716   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:20.774464   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
... skipping 476 lines ...
I0626 14:47:21.755247   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.757157   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.758960   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.760668   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.762423   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.764184   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
E0626 14:47:21.764966   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:47:21.765893   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.767636   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.769299   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.770984   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.772747   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:21.774465   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
... skipping 528 lines ...
I0626 14:47:22.765361   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.766932   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.768537   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.770024   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.771842   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.773772   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
E0626 14:47:22.775007   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:22.775341   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.775537   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/"
I0626 14:47:22.782092   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.782317   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/"
node created: test-mhc-node-qq7hh
E0626 14:47:22.838127   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qq7hh, got []"  "node"="test-mhc-node-qq7hh"
E0626 14:47:22.838167   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qq7hh, got []"  "node"="test-mhc-node-qq7hh"
I0626 14:47:22.844960   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.860001   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.867176   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.867441   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/test-mhc-node-qq7hh"
I0626 14:47:22.880396   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.880676   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/test-mhc-node-qq7hh"
I0626 14:47:22.884747   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.885014   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/test-mhc-node-qq7hh"
Cleaning up nodes, machines and infra machines.
I0626 14:47:22.890999   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:22.891279   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jbthn/test-mhc-wlc22/test-mhc-machine-dnp6w/"
I0626 14:47:22.901887   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dkt99" "namespace"="test-mhc-jbthn" "descendants"="Worker machines: test-mhc-machine-dnp6w" "indirect descendants count"=1
I0626 14:47:22.905485   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dkt99" "namespace"="test-mhc-jbthn" "descendants"="Worker machines: test-mhc-machine-dnp6w" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0626 14:47:22.978326   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" "creating"=1 "need"=1
I0626 14:47:22.978383   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" 
I0626 14:47:22.986258   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-625t7-xvj5r\"" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" 
I0626 14:47:23.058062   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wlc22" "namespace"="test-mhc-jbthn" 
I0626 14:47:23.064275   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:23.076889   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0626 14:47:23.194710   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
E0626 14:47:23.683174   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4g4s6/test-cluster-fmhjl"
I0626 14:47:23.775442   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dkt99" "machine"="test-mhc-machine-dnp6w" "namespace"="test-mhc-jbthn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-qq7hh"}
E0626 14:47:23.834988   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dnp6w\" not found" "controller"="machine" "name"="test-mhc-machine-dnp6w" "namespace"="test-mhc-jbthn"
I0626 14:47:24.195093   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.841830   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.842141   10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.845806   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.845937   10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.852396   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
... skipping 4 lines ...
I0626 14:47:24.860219   10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.865119   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.865147   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.868227   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:24.868267   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.196039   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.196390   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/"
I0626 14:47:25.201494   10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.204509   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.204537   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.205041   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.205278   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/"
I0626 14:47:25.210030   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.210064   10454 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.210339   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/"
I0626 14:47:25.216378   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.216405   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.289009   10454 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-625t7" "namespace"="test-mhc-bh4bs" "machine"="mhc-ms-625t7-xvj5r"
I0626 14:47:25.290159   10454 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "count"=1
I0626 14:47:25.290210   10454 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-625t7"
I0626 14:47:25.292570   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4t7c9" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" "cause"="cluster is being deleted" "node"=null
I0626 14:47:25.292579   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.292874   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/"
I0626 14:47:25.297169   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.297353   10454 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-bh4bs/test-mhc-zqrmb/mhc-ms-625t7-xvj5r/"
I0626 14:47:25.299343   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zqrmb" "namespace"="test-mhc-bh4bs" 
I0626 14:47:25.301084   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "descendants"="Machine sets: mhc-ms-625t7;Worker machines: mhc-ms-625t7-xvj5r" "indirect descendants count"=1
I0626 14:47:25.304730   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4t7c9" "namespace"="test-mhc-bh4bs" "descendants"="Worker machines: mhc-ms-625t7-xvj5r" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0626 14:47:25.320179   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4t7c9" "machine"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs" "cause"="cluster is being deleted" "node"=null
E0626 14:47:25.344034   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-625t7-xvj5r\" not found" "controller"="machine" "name"="mhc-ms-625t7-xvj5r" "namespace"="test-mhc-bh4bs"
I0626 14:47:25.347068   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
inframachine created: test-mhc-machine-infra-2rp8c
I0626 14:47:25.354730   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-hw6ss
I0626 14:47:25.365206   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:25.368576   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
... skipping 587 lines ...
I0626 14:47:26.348955   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.350046   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.350489   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.352138   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.353900   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
node created: test-mhc-node-6fvfg
E0626 14:47:26.361178   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
E0626 14:47:26.361395   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
E0626 14:47:26.361406   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
I0626 14:47:26.362234   10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-hw6ss" "namespace"="test-mhc-nqhxt" "noderef"="test-mhc-node-6fvfg"
E0626 14:47:26.365517   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
E0626 14:47:26.365592   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
E0626 14:47:26.365692   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
E0626 14:47:26.365736   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
E0626 14:47:26.366197   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
E0626 14:47:26.366282   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6fvfg, got []"  "node"="test-mhc-node-6fvfg"
I0626 14:47:26.381507   10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "remediation request name"="test-mhc-machine-hw6ss" "target"="test-mhc-nqhxt/test-mhc-ghs98/test-mhc-machine-hw6ss/"
I0626 14:47:26.388924   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.402482   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.409814   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.412210   10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "remediation request name"="test-mhc-machine-hw6ss" "target"="test-mhc-nqhxt/test-mhc-ghs98/test-mhc-machine-hw6ss/test-mhc-node-6fvfg"
I0626 14:47:26.422515   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.426455   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
Cleaning up nodes, machines and infra machines.
I0626 14:47:26.435111   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.441643   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
I0626 14:47:26.445809   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n8ggt" "namespace"="test-mhc-nqhxt" "descendants"="Worker machines: test-mhc-machine-hw6ss" "indirect descendants count"=1
I0626 14:47:26.449489   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n8ggt" "namespace"="test-mhc-nqhxt" "descendants"="Worker machines: test-mhc-machine-hw6ss" "indirect descendants count"=1
I0626 14:47:26.449513   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ghs98" "namespace"="test-mhc-nqhxt" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0626 14:47:26.511039   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n8ggt" "machine"="test-mhc-machine-hw6ss" "namespace"="test-mhc-nqhxt" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-6fvfg","uid":"0faf5b5b-b7f8-4d7d-bdee-9c8b51115076","apiVersion":"v1"}
E0626 14:47:26.538421   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-hw6ss\" not found" "controller"="machine" "name"="test-mhc-machine-hw6ss" "namespace"="test-mhc-nqhxt"
I0626 14:47:26.566141   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
inframachine created: test-mhc-machine-infra-7czbf
I0626 14:47:26.578292   10454 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-jdh8q
I0626 14:47:26.592395   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:26.593500   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
... skipping 562 lines ...
I0626 14:47:27.540183   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.541909   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.543426   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.544583   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.545280   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.547282   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
E0626 14:47:27.547583   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
I0626 14:47:27.549742   10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "remediation request name"="test-mhc-machine-jdh8q" "target"="test-mhc-zt7l8/test-mhc-6lgzl/test-mhc-machine-jdh8q/"
I0626 14:47:27.558356   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
E0626 14:47:27.581811   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []"  "node"="test-mhc-node-z9fmn"
E0626 14:47:27.581966   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []"  "node"="test-mhc-node-z9fmn"
E0626 14:47:27.581966   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []"  "node"="test-mhc-node-z9fmn"
node created: test-mhc-node-z9fmn
E0626 14:47:27.582232   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z9fmn, got []"  "node"="test-mhc-node-z9fmn"
I0626 14:47:27.586217   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.598410   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.608915   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.611379   10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "remediation request name"="test-mhc-machine-jdh8q" "target"="test-mhc-zt7l8/test-mhc-6lgzl/test-mhc-machine-jdh8q/test-mhc-node-z9fmn"
I0626 14:47:27.624853   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.626529   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.632657   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.646010   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.650239   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
Cleaning up nodes, machines and infra machines.
I0626 14:47:27.656350   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
I0626 14:47:27.659448   10454 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="" "reason"="NodeNotFound" "remediation request name"="test-mhc-machine-jdh8q" "target"="test-mhc-zt7l8/test-mhc-6lgzl/test-mhc-machine-jdh8q/"
I0626 14:47:27.667975   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hwtmv" "namespace"="test-mhc-zt7l8" "descendants"="Worker machines: test-mhc-machine-jdh8q" "indirect descendants count"=1
I0626 14:47:27.671779   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hwtmv" "namespace"="test-mhc-zt7l8" "descendants"="Worker machines: test-mhc-machine-jdh8q" "indirect descendants count"=1
E0626 14:47:27.672512   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6lgzl\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8"
--- PASS: TestMachineHealthCheck_Reconcile (38.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.25s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.15s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (1.22s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0626 14:47:27.674392   10454 machinehealthcheck_controller.go:416]  "msg"="expected a Cluster" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace
--- PASS: TestClusterToMachineHealthCheck (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace (0.00s)
=== RUN   TestMachineToMachineHealthCheck
=== RUN   TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine
E0626 14:47:27.675320   10454 machinehealthcheck_controller.go:445]  "msg"="expected a Machine" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace
--- PASS: TestMachineToMachineHealthCheck (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace (0.00s)
=== RUN   TestNodeToMachineHealthCheck
=== RUN   TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node
E0626 14:47:27.676296   10454 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0626 14:47:27.676440   10454 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got []"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_two_Machines_exist_for_the_Node
E0626 14:47:27.676693   10454 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0626 14:47:27.678474   10454 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0626 14:47:27.678838   10454 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0626 14:47:27.679821   10454 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0626 14:47:27.685074   10454 machineset_controller.go:151]  "msg"="Failed to reconcile MachineSet" "error"="failed to calculate MachineSet's Status: failed to calculate status for MachineSet default/machineset1: invalid label key \"--$-invalid\": name part must consist of alphanumeric characters, '-', '_' or '.', and must start and end with an alphanumeric character (e.g. 'MyName',  or 'my.name',  or '123-abc', regex used for validation is '([A-Za-z0-9][-A-Za-z0-9_.]*)?[A-Za-z0-9]')" "machineset"="machineset1" "namespace"="default" 
--- PASS: TestMachineSetReconcile (0.00s)
    --- PASS: TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion (0.00s)
    --- PASS: TestMachineSetReconcile/records_event_if_reconcile_fails (0.00s)
=== RUN   TestMachineSetToMachines
=== RUN   TestMachineSetToMachines/should_return_empty_request_when_controller_is_set
=== RUN   TestMachineSetToMachines/should_return_nil_if_machine_has_no_owner_reference
... skipping 8 lines ...
--- PASS: TestAdoptOrphan (0.00s)
=== RUN   TestHasMatchingLabels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_has_empty_selector
=== RUN   TestHasMatchingLabels/machine_set_has_bad_selector
E0626 14:47:27.686157   10454 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 65 lines ...
I0626 14:47:27.747506   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-xhxbv-s45s6\"" "machineset"="ms-xhxbv" "namespace"="ms-test" 
I0626 14:47:27.747554   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-xhxbv" "namespace"="ms-test" 
I0626 14:47:27.757297   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-xhxbv-f2zhm\"" "machineset"="ms-xhxbv" "namespace"="ms-test" 
I0626 14:47:27.860038   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-xhxbv" "namespace"="ms-test" "creating"=1 "need"=2
I0626 14:47:27.860071   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-xhxbv" "namespace"="ms-test" 
I0626 14:47:27.870100   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-xhxbv-hhk4s\"" "machineset"="ms-xhxbv" "namespace"="ms-test" 
E0626 14:47:27.913951   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jbthn/test-cluster-dkt99"
E0626 14:47:27.969944   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:27.969948   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:27.970181   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:28.073279   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:28.073319   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:28.073322   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:28.073360   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:28.073460   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:28.073487   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-s45s6-89pmg, got []"  "node"="ms-xhxbv-s45s6-89pmg"
E0626 14:47:28.095118   10454 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-xhxbv-s45s6-89pmg for machine ms-test/ms-xhxbv-s45s6: the cache is not started, can not read objects" "machineset"="ms-xhxbv" "namespace"="ms-test" 
E0626 14:47:28.099896   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.099908   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.100036   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.102416   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.102460   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.102467   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.102486   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.102528   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
E0626 14:47:28.102578   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-xhxbv-hhk4s-fp9qm, got []"  "node"="ms-xhxbv-hhk4s-fp9qm"
I0626 14:47:28.218202   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2
•I0626 14:47:28.221588   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2
I0626 14:47:28.260156   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0626 14:47:28.260212   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" 
I0626 14:47:28.269098   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-lwq6r-6657c7fddb-27b6t\"" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" 
I0626 14:47:28.269199   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" 
... skipping 6 lines ...
I0626 14:47:28.476665   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0626 14:47:28.476713   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" 
I0626 14:47:28.505632   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-6657c7fddb-h5lcz\"" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" 
I0626 14:47:28.548124   10454 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hwtmv" "machine"="test-mhc-machine-jdh8q" "namespace"="test-mhc-zt7l8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-z9fmn"}
I0626 14:47:28.586363   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0626 14:47:28.586408   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" 
E0626 14:47:28.587348   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jdh8q\" not found" "controller"="machine" "name"="test-mhc-machine-jdh8q" "namespace"="test-mhc-zt7l8"
I0626 14:47:28.602786   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-cdfc6fd6c-cxgp8\"" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" 
I0626 14:47:28.674142   10454 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6lgzl" "namespace"="test-mhc-zt7l8" 
E0626 14:47:28.679779   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.679792   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.679867   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.682190   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.682293   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.682190   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.682331   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.682235   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.682361   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr, got []"  "node"="md-lwq6r-cdfc6fd6c-cxgp8-z2ggr"
E0626 14:47:28.707370   10454 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-lwq6r-cdfc6fd6c-cxgp8-z2ggr for machine md-test/md-lwq6r-cdfc6fd6c-cxgp8: the cache is not started, can not read objects" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" 
I0626 14:47:28.726481   10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0626 14:47:28.726520   10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0626 14:47:28.730274   10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "machine"="md-lwq6r-6657c7fddb-h5lcz"
I0626 14:47:28.837991   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0626 14:47:28.838036   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" 
I0626 14:47:28.847613   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-cdfc6fd6c-5pvjd\"" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" 
E0626 14:47:28.917950   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:28.917992   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:28.918218   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:29.020941   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:29.020991   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:29.020941   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:29.021024   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:29.020941   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
E0626 14:47:29.021075   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-5pvjd-lzt7k, got []"  "node"="md-lwq6r-cdfc6fd6c-5pvjd-lzt7k"
I0626 14:47:29.078723   10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0626 14:47:29.078758   10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0626 14:47:29.082298   10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "machine"="md-lwq6r-6657c7fddb-2crgd"
I0626 14:47:29.097836   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0626 14:47:29.097869   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" 
I0626 14:47:29.105179   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-cdfc6fd6c-4mzs5\"" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" 
E0626 14:47:29.138918   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.138918   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.139109   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.241351   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.241402   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.241413   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.241449   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.241788   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
E0626 14:47:29.241850   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-cdfc6fd6c-4mzs5-n8mcj, got []"  "node"="md-lwq6r-cdfc6fd6c-4mzs5-n8mcj"
I0626 14:47:29.273692   10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0626 14:47:29.273803   10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0626 14:47:29.280704   10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-6657c7fddb" "namespace"="md-test" "machine"="md-lwq6r-6657c7fddb-2pmts"
I0626 14:47:29.414863   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0626 14:47:29.414919   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" 
I0626 14:47:29.428592   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-74d45c49c5-wpk9x\"" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" 
E0626 14:47:29.512142   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.512157   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.512158   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.514954   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.514966   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.515005   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.515012   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.514965   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
E0626 14:47:29.515044   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-wpk9x-48xpp, got []"  "node"="md-lwq6r-74d45c49c5-wpk9x-48xpp"
I0626 14:47:29.546129   10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0626 14:47:29.546170   10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0626 14:47:29.551263   10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "machine"="md-lwq6r-cdfc6fd6c-4mzs5"
E0626 14:47:29.606022   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:29.662267   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0626 14:47:29.662318   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" 
I0626 14:47:29.671034   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-74d45c49c5-fzc8v\"" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" 
E0626 14:47:29.741368   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.741452   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.741452   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.744062   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.744104   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.744136   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.744168   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.744205   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
E0626 14:47:29.744248   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-fzc8v-5sjp9, got []"  "node"="md-lwq6r-74d45c49c5-fzc8v-5sjp9"
I0626 14:47:29.779958   10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0626 14:47:29.780038   10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0626 14:47:29.783192   10454 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "machine"="md-lwq6r-cdfc6fd6c-5pvjd"
I0626 14:47:29.892180   10454 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0626 14:47:29.892215   10454 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" 
I0626 14:47:29.902629   10454 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-lwq6r-74d45c49c5-2bz4z\"" "machineset"="md-lwq6r-74d45c49c5" "namespace"="md-test" 
E0626 14:47:29.997150   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:29.997388   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:29.997821   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:30.100446   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:30.100509   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:30.100447   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:30.100547   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:30.100595   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
E0626 14:47:30.100657   10454 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-lwq6r-74d45c49c5-2bz4z-sgcdw, got []"  "node"="md-lwq6r-74d45c49c5-2bz4z-sgcdw"
I0626 14:47:30.127504   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x,md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-cdfc6fd6c-cxgp8,md-lwq6r-6657c7fddb-27b6t" "indirect descendants count"=8
I0626 14:47:30.131102   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-cdfc6fd6c,md-lwq6r-74d45c49c5;Worker machines: md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-cdfc6fd6c-cxgp8,md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x" "indirect descendants count"=8
•I0626 14:47:30.132254   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0626 14:47:30.134366   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-lwq6r\" not found" "controller"="machinedeployment" "name"="md-lwq6r" "namespace"="md-test"
I0626 14:47:30.134896   10454 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0626 14:47:30.134961   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0626 14:47:30.135046   10454 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0626 14:47:30.135073   10454 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-lwq6r-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0626 14:47:30.136347   10454 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0626 14:47:30.136379   10454 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
... skipping 15 lines ...
I0626 14:47:30.150814   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
•I0626 14:47:30.152855   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0626 14:47:30.153814   10454 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0626 14:47:30.154769   10454 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0626 14:47:30.154812   10454 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0626 14:47:30.155673   10454 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0626 14:47:30.157692   10454 machine_controller.go:494]  "msg"="Error creating a remote client while deleting Machine, won't retry" "error"="failed to create REST configuration for Cluster default/test-cluster: invalid configuration: no configuration has been provided" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" 
••E0626 14:47:30.279081   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-shs4p\" not found" "controller"="cluster" "name"="test1-shs4p" "namespace"="default"
I0626 14:47:30.705192   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:30.705223   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:30.718193   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
I0626 14:47:30.718220   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
E0626 14:47:30.741942   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
E0626 14:47:31.294426   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-bh4bs/test-cluster-4t7c9"
•I0626 14:47:31.394569   10454 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-f5zkb" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0626 14:47:31.508165   10454 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-f5zkb" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0626 14:47:31.511482   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
E0626 14:47:31.782427   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
E0626 14:47:32.526151   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-nqhxt/test-cluster-n8ggt"
E0626 14:47:32.528473   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
•I0626 14:47:32.805442   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:32.805480   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:32.808271   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
I0626 14:47:32.808299   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
E0626 14:47:32.811650   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
E0626 14:47:33.540206   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-6qqdp\" not found" "controller"="cluster" "name"="test3-6qqdp" "namespace"="default"
E0626 14:47:33.823000   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
E0626 14:47:34.540809   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
E0626 14:47:34.831167   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
I0626 14:47:35.556646   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2
E0626 14:47:35.556651   10454 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zt7l8/test-cluster-hwtmv"
E0626 14:47:35.557201   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
•I0626 14:47:35.835163   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:35.835195   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:35.838252   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
I0626 14:47:35.838283   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
E0626 14:47:35.841665   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
I0626 14:47:36.557728   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x" "indirect descendants count"=7
E0626 14:47:36.561496   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
E0626 14:47:36.846203   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
E0626 14:47:37.562256   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
E0626 14:47:37.850908   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
E0626 14:47:38.570038   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
•I0626 14:47:38.855457   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:38.855494   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:38.858678   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
I0626 14:47:38.858709   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
E0626 14:47:38.862110   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
E0626 14:47:39.570759   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
E0626 14:47:39.862445   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-ls8zp\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-ls8zp" "namespace"="test-mhc-brccc"
E0626 14:47:40.571461   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
E0626 14:47:40.866598   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
E0626 14:47:41.580271   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
E0626 14:47:41.870660   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
I0626 14:47:42.580670   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-hhk4s,ms-xhxbv-s45s6" "indirect descendants count"=2
E0626 14:47:42.581118   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
E0626 14:47:42.870977   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-mj26m\" for machine \"test-mhc-machine-dwh4p\" in namespace \"test-mhc-brccc\": Cluster.cluster.x-k8s.io \"test-cluster-mj26m\" not found" "controller"="machine" "name"="test-mhc-machine-dwh4p" "namespace"="test-mhc-brccc"
I0626 14:47:43.581521   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x,md-lwq6r-74d45c49c5-2bz4z" "indirect descendants count"=7
E0626 14:47:43.582061   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
I0626 14:47:43.874665   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:43.874705   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:43.878100   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
I0626 14:47:43.878133   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
E0626 14:47:43.883281   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
E0626 14:47:44.582788   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
E0626 14:47:44.896429   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
E0626 14:47:45.583418   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
E0626 14:47:45.900686   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
E0626 14:47:46.584017   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
I0626 14:47:46.904367   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:46.904402   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-27b6t" "namespace"="md-test" 
I0626 14:47:46.907426   10454 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
I0626 14:47:46.907452   10454 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-lwq6r-6657c7fddb-7txwl" "namespace"="md-test" 
I0626 14:47:46.918591   10454 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dtbh8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0626 14:47:46.926519   10454 machine_controller_noderef.go:73] controllers/Machine "msg"="Failed to retrieve Node by ProviderID" "error"="the cache is not started, can not read objects" "machine"="test6-dtbh8" "namespace"="default" 
E0626 14:47:46.937918   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\", the cache is not started, can not read objects]" "controller"="machine" "name"="test6-dtbh8" "namespace"="default"
E0626 14:47:47.584611   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
E0626 14:47:47.942221   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-wpk9x\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-wpk9x" "namespace"="md-test"
E0626 14:47:48.585187   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-f5zkb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-f5zkb" "namespace"="default"
E0626 14:47:48.946409   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-lwq6r-74d45c49c5-fzc8v\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-lwq6r-74d45c49c5-fzc8v" "namespace"="md-test"
I0626 14:47:49.585654   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-xhxbv-s45s6,ms-xhxbv-hhk4s" "indirect descendants count"=2
E0626 14:47:49.586161   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"
I0626 14:47:49.959283   10454 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dtbh8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0626 14:47:49.959485   10454 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-dtbh8" "namespace"="default" "noderef"="id-node-1"
E0626 14:47:49.968963   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="machine" "name"="test6-dtbh8" "namespace"="default"
I0626 14:47:50.586629   10454 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-lwq6r-74d45c49c5,md-lwq6r-cdfc6fd6c;Worker machines: md-lwq6r-74d45c49c5-2bz4z,md-lwq6r-6657c7fddb-27b6t,md-lwq6r-6657c7fddb-7txwl,md-lwq6r-74d45c49c5-fzc8v,md-lwq6r-74d45c49c5-wpk9x" "indirect descendants count"=7
E0626 14:47:50.590367   10454 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6rsc4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6rsc4" "namespace"="default"

------------------------------
• [SLOW TEST:12.042 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
------------------------------


Ran 16 of 16 Specs in 22.987 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (22.99s)
PASS
Tearing down test suite
I0626 14:47:50.674361   10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0626 14:47:50.674407   10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0626 14:47:50.674423   10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0626 14:47:50.674438   10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0626 14:47:50.674406   10454 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0626 14:47:50.674451   10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0626 14:47:50.674371   10454 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
E0626 14:47:50.701176   10454 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:40957/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1301&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:40957: connect: connection refused
E0626 14:47:50.701177   10454 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:40957/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1301&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:40957: connect: connection refused
E0626 14:47:50.701177   10454 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:40957/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1301&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:40957: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	76.634s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
I0626 14:46:46.679462   10981 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0626 14:46:47.217431   10981 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0626 14:46:47.237470   10981 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0626 14:46:47.337861   10981 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0626 14:46:47.337914   10981 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0626 14:46:47.515220   10981 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0626 14:46:49.542381   10981 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-54rg8/test-cluster"
•E0626 14:46:49.991815   10981 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-fn5z5/test-cluster"
•E0626 14:46:50.523640   10981 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:35113/?timeout=50ms: dial tcp 127.0.0.1:35113: connect: connection refused"  "cluster"="cluster-cache-test-tffhd/test-cluster"
•E0626 14:46:50.736031   10981 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0626 14:46:50.736072   10981 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-431684687/tls.crt: no such file or directory"  
E0626 14:46:50.736089   10981 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0626 14:46:50.736103   10981 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-431684687/tls.crt: no such file or directory"  
I0626 14:46:50.736119   10981 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0626 14:46:50.779754   10981 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1alpha3.Cluster: Get http://127.0.0.1:33287/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:33287: connect: connection refused


Ran 5 of 5 Specs in 14.814 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (14.81s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	14.930s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 208 lines ...
=== RUN   TestReconcileNoClusterOwnerRef
I0626 14:46:57.244977   11517 controller.go:130]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0626 14:46:57.246277   11517 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0626 14:46:57.246850   11517 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0626 14:46:57.246997   11517 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0626 14:47:11.323609   11517 scale.go:173]  "msg"="Waiting for machines to be deleted" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Machines"=""
=== RUN   TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue
I0626 14:47:11.323711   11517 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "failures"="machine  reports APIServerPodHealthy condition is false (Error, )"
=== RUN   TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass
--- PASS: TestPreflightChecks (0.00s)
    --- PASS: TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass (0.00s)
... skipping 18 lines ...
=== RUN   TestAPIs
Running Suite: Controller Suite
===============================
Random Seed: 1656254804
Will run 1 of 1 specs

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

Ran 1 of 1 Specs in 0.016 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0626 14:47:11.343567   11517 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-eqd2nm" "kubeadmControlPlane"="kcp-foo-eqd2nm" "namespace"="test" 
I0626 14:47:12.804313   11517 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-eqd2nm" "kubeadmControlPlane"="kcp-foo-eqd2nm" "namespace"="test" "needRollout"=["kcp-foo-eqd2nm-gvh8m"]
I0626 14:47:12.804512   11517 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-eqd2nm" "kubeadmControlPlane"="kcp-foo-eqd2nm" "namespace"="test" "failures"="[machine kcp-foo-eqd2nm-lcsq7 does not have APIServerPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have ControllerManagerPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have SchedulerPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have EtcdPodHealthy condition, machine kcp-foo-eqd2nm-lcsq7 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.46s)
... skipping 60 lines ...
==================================
Random Seed: 1656254804
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: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1656254804
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0626 14:46:59.594256   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:47:07.917365   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:47:16.903326   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:47:28.033542   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:47:44.506735   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:47:57.515376   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:48:15.162752   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:48:36.086035   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:49:07.102575   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0626 14:49:52.259653   11484 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
E0626 14:49:52.268630   11484 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0626 14:49:52.268675   11484 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-417642536/tls.crt: no such file or directory"  
E0626 14:49:52.268690   11484 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0626 14:49:52.268705   11484 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-417642536/tls.crt: no such file or directory"  
I0626 14:49:52.269436   11484 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.106s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0626 14:47:04.898370   11826 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0626 14:47:04.898643   11826 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0626 14:47:04.999055   11826 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0626 14:47:05.099620   11826 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0626 14:47:05.099704   11826 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0626 14:47:05.201955   11826 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-umy3n4"} 
E0626 14:47:05.228096   11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•I0626 14:47:06.284854   11826 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-nazad5"} 
•E0626 14:47:06.329732   11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0626 14:47:07.437386   11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0626 14:47:08.462501   11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0626 14:47:09.571532   11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0626 14:47:10.590758   11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset2\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset2" "namespace"="default"
•E0626 14:47:11.601485   11826 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•I0626 14:47:11.606433   11826 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0626 14:47:11.606455   11826 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0626 14:47:11.606490   11826 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0626 14:47:11.606493   11826 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-688416601/tls.crt: no such file or directory"  
I0626 14:47:11.606506   11826 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0626 14:47:11.606522   11826 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0626 14:47:11.606539   11826 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-688416601/tls.crt: no such file or directory"  


Ran 5 of 5 Specs in 19.468 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (19.47s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	19.532s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0626 14:46:56.770314   12034 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 95 lines ...
•I0626 14:47:07.607924   12034 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0626 14:47:07.645030   12034 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0626 14:47:07.647803   12034 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 10.815 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (10.82s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.091s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 209 lines ...
Patch Helper
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39
  Should patch conditions
  /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:102
    on a clusterv1.Cluster object
    /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:150
      should not return an error if there is an unresolvable conflict when force overwrite is enabled [It]
      /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:366

      Expected success, but got an error:
          <errors.aggregate | len:1, cap:1>: [
              {
                  ErrStatus: {
                      TypeMeta: {Kind: "", APIVersion: ""},
                      ListMeta: {
                          SelfLink: "",
... skipping 33 lines ...
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39
  Should patch a clusterv1.Cluster
  /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:411
    updating both spec, status, and adding a condition [It]
    /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:550

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



Summarizing 2 Failures:

[Fail] Patch Helper Should patch conditions on a clusterv1.Cluster object [It] should not return an error if there is an unresolvable conflict when force overwrite is enabled 
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:392

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

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