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

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0611 14:42:32.820525    8530 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0611 14:42:33.603913    8530 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" 
•I0611 14:42:33.626094    8530 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.006 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.01s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	46.311s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1399 lines ...
I0611 14:42:17.929018   10461 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0611 14:42:17.929051   10461 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0611 14:42:17.929086   10461 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0611 14:42:17.929262   10461 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
I0611 14:42:17.930021   10461 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
=== RUN   TestClusterReconcilePhases
2022/06/11 14:42:18 http: TLS handshake error from 127.0.0.1:58856: EOF
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0611 14:42:18.028006   10461 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"
I0611 14:42:18.036669   10461 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
... skipping 104 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0611 14:42:18.063928   10461 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
I0611 14:42:18.066133   10461 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"
E0611 14:42:18.066495   10461 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
I0611 14:42:18.066908   10461 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
I0611 14:42:18.298668   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0611 14:42:18.301255   10461 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0611 14:42:18.311313   10461 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0611 14:42:18.311432   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0611 14:42:18.420937   10461 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0611 14:42:18.421029   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0611 14:42:18.521482   10461 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc" "noderef"="node-1"
E0611 14:42:18.533177   10461 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0611 14:42:18.533224   10461 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0611 14:42:18.560364   10461 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc" "noderef"="node-1"
E0611 14:42:18.602851   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-ctm2w\" in namespace \"test-machine-watches-sh4nc\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc"
E0611 14:42:19.607325   10461 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-ctm2w\" in namespace \"test-machine-watches-sh4nc\", requeuing: requeue in 1s"  
E0611 14:42:19.616123   10461 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-ctm2w\" in namespace \"test-machine-watches-sh4nc\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-ctm2w\" in namespace \"test-machine-watches-sh4nc\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc"
--- PASS: TestWatches (1.61s)
=== 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
I0611 14:42:19.847160   10461 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-zqnsx" "namespace"="test-machine-watches-sh4nc" "count"=1
I0611 14:42:19.847229   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-zqnsx" "namespace"="test-machine-watches-sh4nc" "descendants"="Worker machines: machine-created-ctm2w" "indirect descendants count"=0
I0611 14:42:19.863299   10461 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-zqnsx" "namespace"="test-machine-watches-sh4nc" "count"=1
I0611 14:42:19.863377   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-zqnsx" "namespace"="test-machine-watches-sh4nc" "descendants"="Worker machines: machine-created-ctm2w" "indirect descendants count"=0
I0611 14:42:20.616661   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zqnsx" "machine"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"1823a5d4-2706-470e-8ba0-97821ba09c61","apiVersion":"v1"}
E0611 14:42:20.688064   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-ctm2w\" not found" "controller"="machine" "name"="machine-created-ctm2w" "namespace"="test-machine-watches-sh4nc"
E0611 14:42:21.746920   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-xcfcj\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-6jpk7\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-6jpk7: secrets \"machine-reconcile-6jpk7-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-xcfcj" "namespace"="default"
I0611 14:42:22.747520   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-6jpk7" "machine"="machine-created-xcfcj" "namespace"="default" "cause"="noderef is nil" "node"=null
I0611 14:42:22.781697   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-6jpk7" "machine"="machine-created-xcfcj" "namespace"="default" "cause"="noderef is nil" "node"=null
I0611 14:42:22.802540   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-6jpk7" "machine"="machine-created-xcfcj" "namespace"="default" "cause"="noderef is nil" "node"=null
E0611 14:42:22.843703   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-xcfcj\" not found" "controller"="machine" "name"="machine-created-xcfcj" "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)
    --- PASS: TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one (0.00s)
    --- PASS: TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer (0.00s)
=== RUN   TestMachineOwnerReference
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0611 14:42:22.861165   10461 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0611 14:42:22.861270   10461 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
E0611 14:42:22.876820   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-6jpk7\" not found" "controller"="cluster" "name"="machine-reconcile-6jpk7" "namespace"="default"
I0611 14:42:22.878880   10461 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0611 14:42:22.879005   10461 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0611 14:42:22.882441   10461 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0611 14:42:22.882618   10461 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.02s)
... skipping 123 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0611 14:42:23.137208   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-csjzz" "namespace"="test-mhc-kn7c7" 
I0611 14:42:23.160892   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0611 14:42:23.161533   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-ssbk6\" not found"  "cluster"="test-mhc-kn7c7/test-cluster-ssbk6"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0611 14:42:23.185512   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-csjzz\" not found" "controller"="machinehealthcheck" "name"="test-mhc-csjzz" "namespace"="test-mhc-kn7c7"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0611 14:42:24.187539   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-csjzz" "namespace"="test-mhc-kn7c7" 
I0611 14:42:24.187655   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xjmtp" "namespace"="test-mhc-jh5qm" 
I0611 14:42:24.187701   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8mvl6" "namespace"="test-mhc-lkltm" 
I0611 14:42:24.187737   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qzfhl" "namespace"="test-mhc-mws5z" 
I0611 14:42:24.212137   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0611 14:42:24.229570   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qzfhl" "namespace"="test-mhc-mws5z" 
I0611 14:42:24.273563   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qzfhl" "namespace"="test-mhc-mws5z" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0611 14:42:24.298146   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mws5z/test-cluster-9vkzn"
E0611 14:42:24.298482   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-9vkzn\" not found" "controller"="cluster" "name"="test-cluster-9vkzn" "namespace"="test-mhc-mws5z"
I0611 14:42:24.307524   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fn44v" "namespace"="test-mhc-5pd54" 
I0611 14:42:24.321365   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0611 14:42:24.441753   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fn44v" "namespace"="test-mhc-5pd54" 
I0611 14:42:24.446923   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fn44v" "namespace"="test-mhc-5pd54" 
E0611 14:42:24.513813   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5pd54/test-cluster-vfd5h"
I0611 14:42:24.518352   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fn44v" "namespace"="test-mhc-5pd54" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0611 14:42:24.638101   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
inframachine created: test-mhc-machine-infra-gxxkv
I0611 14:42:24.673670   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-mzsks
I0611 14:42:24.695947   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.705329   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.705678   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-mzsks/"
I0611 14:42:24.724502   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.724910   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-mzsks/"
I0611 14:42:24.732247   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.732616   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-mzsks/"
I0611 14:42:24.746256   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.746640   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-mzsks/"
I0611 14:42:24.764143   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.764578   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-mzsks/"
I0611 14:42:24.770213   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.770679   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-mzsks/"
node created: test-mhc-node-6dq66
E0611 14:42:24.791428   10461 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6dq66"
E0611 14:42:24.791693   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6dq66, got []"  "node"="test-mhc-node-6dq66"
I0611 14:42:24.796001   10461 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9" "noderef"="test-mhc-node-6dq66"
E0611 14:42:24.822100   10461 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6dq66"
E0611 14:42:24.822164   10461 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6dq66"
E0611 14:42:24.822350   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6dq66, got []"  "node"="test-mhc-node-6dq66"
E0611 14:42:24.822388   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6dq66, got []"  "node"="test-mhc-node-6dq66"
I0611 14:42:24.824361   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
inframachine created: test-mhc-machine-infra-4rgj6
machine created: test-mhc-machine-b9c9w
I0611 14:42:24.848030   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.853864   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.859806   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
... skipping 49 lines ...
I0611 14:42:24.993834   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:24.999038   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.000503   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.001707   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.002747   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.004048   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.004424   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-b9c9w/"
I0611 14:42:25.014892   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.015395   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-b9c9w/"
I0611 14:42:25.021616   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.022069   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-b9c9w/"
I0611 14:42:25.045203   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.045901   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-b9c9w/"
E0611 14:42:25.052284   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-j8zmp, got []"  "node"="test-mhc-node-j8zmp"
E0611 14:42:25.052682   10461 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-j8zmp"
node created: test-mhc-node-j8zmp
I0611 14:42:25.059989   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.060481   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-b9c9w/"
I0611 14:42:25.066707   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.067181   10461 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-zgxv9/test-mhc-srfj2/test-mhc-machine-b9c9w/"
I0611 14:42:25.080218   10461 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9" "noderef"="test-mhc-node-j8zmp"
I0611 14:42:25.082934   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.172039   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
Cleaning up nodes, machines and infra machines.
I0611 14:42:25.196881   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:25.197409   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zgxv9/test-mhc-srfj2/test-mhc-machine-mzsks/"
E0611 14:42:25.250639   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zgxv9/test-cluster-6d6jg"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-nmqj2
machine created: test-mhc-machine-mf2tl
E0611 14:42:25.317856   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
E0611 14:42:25.331971   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-sh4nc/machine-reconcile-zqnsx"
E0611 14:42:25.366153   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-srfj2\" not found" "controller"="machinehealthcheck" "name"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9"
E0611 14:42:26.334354   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:26.366493   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:26.400973   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0611 14:42:26.401306   10461 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-czp9p/test-mhc-gl5j4/test-mhc-machine-mf2tl/"
E0611 14:42:26.408609   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mtg8w, got []"  "node"="test-mhc-node-mtg8w"
node created: test-mhc-node-mtg8w
inframachine created: test-mhc-machine-infra-29rr8
I0611 14:42:26.438535   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-srfj2" "namespace"="test-mhc-zgxv9" 
I0611 14:42:26.438638   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
machine created: test-mhc-machine-xddjd
I0611 14:42:26.487053   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
... skipping 287 lines ...
I0611 14:42:27.312366   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.314477   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.322350   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.327431   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.331955   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.334457   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
E0611 14:42:27.335857   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:27.336972   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.339199   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.341403   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.355878   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.358600   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:27.360908   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
... skipping 364 lines ...
I0611 14:42:28.371626   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.374219   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.376615   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.378415   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.380523   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.384570   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
E0611 14:42:28.385493   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:28.386871   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.388389   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.389871   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.391217   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.392551   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:28.393922   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
... skipping 364 lines ...
I0611 14:42:29.391743   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.394061   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.395203   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.396474   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.397542   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.398941   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.399319   10461 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-czp9p/test-mhc-gl5j4/test-mhc-machine-xddjd/"
E0611 14:42:29.399323   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:29.409777   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.410264   10461 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-czp9p/test-mhc-gl5j4/test-mhc-machine-xddjd/"
node created: test-mhc-node-64dvx
E0611 14:42:29.474436   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-64dvx, got []"  "node"="test-mhc-node-64dvx"
I0611 14:42:29.481185   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
inframachine created: test-mhc-machine-infra-4c9qm
machine created: test-mhc-machine-l9vgt
I0611 14:42:29.498719   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.504976   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:29.506444   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
... skipping 229 lines ...
I0611 14:42:30.400742   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.403314   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.405928   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.408472   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.411163   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.413829   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
E0611 14:42:30.416777   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:30.416883   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.422370   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.424073   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.425490   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.435055   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:30.436684   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
... skipping 213 lines ...
I0611 14:42:31.445961   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.450960   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.454184   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.470396   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.472223   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.474317   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
E0611 14:42:31.505898   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:31.506336   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.508115   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.509818   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.511481   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.512985   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:31.532459   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
... skipping 283 lines ...
I0611 14:42:32.503304   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.507076   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.511149   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.515156   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.518780   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.521619   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
E0611 14:42:32.538827   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:32.539248   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.540066   10461 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-czp9p/test-mhc-gl5j4/test-mhc-machine-l9vgt/"
I0611 14:42:32.552189   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.552731   10461 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-czp9p/test-mhc-gl5j4/test-mhc-machine-l9vgt/"
E0611 14:42:32.636079   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tx2mm, got []"  "node"="test-mhc-node-tx2mm"
node created: test-mhc-node-tx2mm
Cleaning up nodes, machines and infra machines.
I0611 14:42:32.647061   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.647807   10461 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-czp9p/test-mhc-gl5j4/test-mhc-machine-l9vgt/test-mhc-node-tx2mm"
I0611 14:42:32.667077   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.667610   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-l9vgt/"
Cleaning up nodes, machines and infra machines.
I0611 14:42:32.687816   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.688524   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-mf2tl/"
I0611 14:42:32.702646   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-xddjd/"
I0611 14:42:32.717127   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-l9vgt/"
I0611 14:42:32.729962   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.730600   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-mf2tl/"
I0611 14:42:32.731112   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-xddjd/"
I0611 14:42:32.731591   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-l9vgt/"
I0611 14:42:32.736970   10461 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-svl29" "namespace"="test-mhc-czp9p" "count"=2
I0611 14:42:32.737057   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-svl29" "namespace"="test-mhc-czp9p" "descendants"="Worker machines: test-mhc-machine-mf2tl,test-mhc-machine-xddjd,test-mhc-machine-l9vgt" "indirect descendants count"=1
I0611 14:42:32.743190   10461 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-svl29" "namespace"="test-mhc-czp9p" "count"=2
I0611 14:42:32.743426   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-svl29" "namespace"="test-mhc-czp9p" "descendants"="Worker machines: test-mhc-machine-mf2tl,test-mhc-machine-xddjd,test-mhc-machine-l9vgt" "indirect descendants count"=1
I0611 14:42:32.746551   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.750989   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-xddjd/"
I0611 14:42:32.752106   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-l9vgt/"
I0611 14:42:32.755707   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-czp9p/test-mhc-gl5j4/test-mhc-machine-mf2tl/"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0611 14:42:32.757301   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gl5j4" "namespace"="test-mhc-czp9p" 
I0611 14:42:32.782456   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
inframachine created: test-mhc-machine-infra-pd8zn
machine created: test-mhc-machine-lsb7w
I0611 14:42:32.820840   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
... skipping 2 lines ...
I0611 14:42:32.968813   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:33.010165   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:33.091142   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:33.252242   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:33.539512   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-svl29" "machine"="test-mhc-machine-xddjd" "namespace"="test-mhc-czp9p" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-64dvx"}
I0611 14:42:33.573319   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:33.589067   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xddjd\" not found" "controller"="machine" "name"="test-mhc-machine-xddjd" "namespace"="test-mhc-czp9p"
I0611 14:42:34.214321   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:34.589479   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:35.495319   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:35.589983   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-svl29" "machine"="test-mhc-machine-l9vgt" "namespace"="test-mhc-czp9p" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-tx2mm"}
E0611 14:42:35.651090   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l9vgt\" not found" "controller"="machine" "name"="test-mhc-machine-l9vgt" "namespace"="test-mhc-czp9p"
E0611 14:42:36.651470   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:37.655548   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-svl29" "machine"="test-mhc-machine-mf2tl" "namespace"="test-mhc-czp9p" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mtg8w"}
E0611 14:42:37.707032   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mf2tl\" not found" "controller"="machine" "name"="test-mhc-machine-mf2tl" "namespace"="test-mhc-czp9p"
E0611 14:42:37.765609   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-czp9p/test-cluster-svl29"
I0611 14:42:38.056285   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:38.716090   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:38.724198   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:38.724205   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:38.746893   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:38.767633   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vxxh2, got []"  "node"="test-mhc-node-vxxh2"
node created: test-mhc-node-vxxh2
I0611 14:42:38.778052   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
inframachine created: test-mhc-machine-infra-dpcm4
machine created: test-mhc-machine-94lst
I0611 14:42:38.811604   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:38.989533   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:38.994663   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:39.015921   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:39.057330   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:39.138688   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:39.300238   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:39.623204   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:39.724609   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:40.266675   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.739911   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.747811   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.760828   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.768228   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.775998   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.782342   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:40.789893   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:40.819665   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
node created: test-mhc-node-vc65r
E0611 14:42:40.836271   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vc65r, got []"  "node"="test-mhc-node-vc65r"
I0611 14:42:40.843719   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
inframachine created: test-mhc-machine-infra-67vqm
I0611 14:42:40.856109   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
machine created: test-mhc-machine-8gq8r
I0611 14:42:40.860792   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.877833   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:40.883969   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:41.548084   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:41.790255   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:42.802373   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:42.820280   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:42.872053   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:42.884968   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:42.889155   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:42.899327   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:42.905170   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:42.905585   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:42.927717   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
E0611 14:42:42.974809   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cgrrr, got []"  "node"="test-mhc-node-cgrrr"
node created: test-mhc-node-cgrrr
I0611 14:42:42.982587   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
Cleaning up nodes, machines and infra machines.
I0611 14:42:43.004995   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:43.020032   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
Cleaning up nodes, machines and infra machines.
... skipping 5 lines ...
inframachine created: test-mhc-machine-infra-plvrv
machine created: test-mhc-machine-kwptc
I0611 14:42:43.152297   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:43.200906   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0611 14:42:43.233432   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fhrc" "namespace"="test-mhc-tfk9h" 
I0611 14:42:43.233554   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
E0611 14:42:43.906193   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:44.906826   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-btwhv" "machine"="test-mhc-machine-lsb7w" "namespace"="test-mhc-tfk9h" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vxxh2"}
E0611 14:42:44.966530   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lsb7w\" not found" "controller"="machine" "name"="test-mhc-machine-lsb7w" "namespace"="test-mhc-tfk9h"
I0611 14:42:45.967778   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-btwhv" "machine"="test-mhc-machine-94lst" "namespace"="test-mhc-tfk9h" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vc65r"}
E0611 14:42:46.012670   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-94lst\" not found" "controller"="machine" "name"="test-mhc-machine-94lst" "namespace"="test-mhc-tfk9h"
I0611 14:42:47.013246   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-btwhv" "machine"="test-mhc-machine-8gq8r" "namespace"="test-mhc-tfk9h" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-cgrrr"}
E0611 14:42:47.054858   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8gq8r\" not found" "controller"="machine" "name"="test-mhc-machine-8gq8r" "namespace"="test-mhc-tfk9h"
I0611 14:42:48.067675   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
E0611 14:42:48.072604   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:48.074096   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
E0611 14:42:48.094373   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tfk9h/test-cluster-btwhv"
E0611 14:42:48.169043   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4tmt2, got []"  "node"="test-mhc-node-4tmt2"
node created: test-mhc-node-4tmt2
I0611 14:42:48.177243   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
inframachine created: test-mhc-machine-infra-hq565
machine created: test-mhc-machine-6swgf
I0611 14:42:48.194723   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:48.203104   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
E0611 14:42:49.072958   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:42:50.086093   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:50.093234   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:50.104719   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:50.112584   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:50.121621   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
E0611 14:42:50.129309   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:50.129616   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
E0611 14:42:50.199996   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vbs6k, got []"  "node"="test-mhc-node-vbs6k"
node created: test-mhc-node-vbs6k
I0611 14:42:50.206809   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
inframachine created: test-mhc-machine-infra-z4mss
machine created: test-mhc-machine-8phbf
I0611 14:42:50.237802   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:50.250233   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.153451   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.166985   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.176615   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.206897   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.211734   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.218580   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.222162   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
E0611 14:42:51.223572   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
Cleaning up nodes, machines and infra machines.
I0611 14:42:51.325699   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
Cleaning up nodes, machines and infra machines.
I0611 14:42:51.334086   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.334580   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hcrwl/test-mhc-lgxh7/test-mhc-machine-kwptc/"
I0611 14:42:51.361806   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:51.362419   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hcrwl/test-mhc-lgxh7/test-mhc-machine-kwptc/"
I0611 14:42:51.362836   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hcrwl/test-mhc-lgxh7/test-mhc-machine-6swgf/"
I0611 14:42:51.384316   10461 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8l7bl" "namespace"="test-mhc-hcrwl" "count"=2
I0611 14:42:51.384404   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8l7bl" "namespace"="test-mhc-hcrwl" "descendants"="Worker machines: test-mhc-machine-kwptc,test-mhc-machine-6swgf,test-mhc-machine-8phbf" "indirect descendants count"=1
I0611 14:42:51.389462   10461 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8l7bl" "namespace"="test-mhc-hcrwl" "count"=2
I0611 14:42:51.389516   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8l7bl" "namespace"="test-mhc-hcrwl" "descendants"="Worker machines: test-mhc-machine-kwptc,test-mhc-machine-6swgf,test-mhc-machine-8phbf" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-47rts
machine created: test-mhc-machine-dwql6
E0611 14:42:51.556285   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-lgxh7\" not found" "controller"="machinehealthcheck" "name"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl"
I0611 14:42:52.224127   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8l7bl" "machine"="test-mhc-machine-kwptc" "namespace"="test-mhc-hcrwl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4tmt2"}
E0611 14:42:52.285825   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kwptc\" not found" "controller"="machine" "name"="test-mhc-machine-kwptc" "namespace"="test-mhc-hcrwl"
I0611 14:42:52.556562   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:52.577600   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0611 14:42:52.596004   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lgxh7" "namespace"="test-mhc-hcrwl" 
I0611 14:42:52.596081   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:52.596842   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:52.598268   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
... skipping 311 lines ...
I0611 14:42:53.321627   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.323365   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.325342   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.327152   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.328902   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.330660   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
E0611 14:42:53.331470   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6swgf\" not found" "controller"="machine" "name"="test-mhc-machine-6swgf" "namespace"="test-mhc-hcrwl"
I0611 14:42:53.332390   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.334126   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.335854   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.337541   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.339267   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:53.341062   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
... skipping 486 lines ...
I0611 14:42:54.362407   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.365651   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.367425   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.369165   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.370914   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.373029   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
E0611 14:42:54.373079   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8phbf\" not found" "controller"="machine" "name"="test-mhc-machine-8phbf" "namespace"="test-mhc-hcrwl"
I0611 14:42:54.375537   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.377248   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.379118   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.380918   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.382524   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:54.384228   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
... skipping 460 lines ...
I0611 14:42:55.383262   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.384902   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.385651   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.386616   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.388326   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.390086   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.390579   10461 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-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/"
E0611 14:42:55.390827   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
I0611 14:42:55.401188   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.401499   10461 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-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/"
E0611 14:42:55.447780   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mhhz4, got []"  "node"="test-mhc-node-mhhz4"
node created: test-mhc-node-mhhz4
E0611 14:42:55.447996   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mhhz4, got []"  "node"="test-mhc-node-mhhz4"
I0611 14:42:55.460646   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.476542   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.489482   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.489853   10461 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-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/test-mhc-node-mhhz4"
I0611 14:42:55.514121   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.514557   10461 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-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/test-mhc-node-mhhz4"
I0611 14:42:55.518524   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.518775   10461 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-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/test-mhc-node-mhhz4"
Cleaning up nodes, machines and infra machines.
I0611 14:42:55.530378   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.530727   10461 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-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/test-mhc-node-mhhz4"
I0611 14:42:55.532107   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.532372   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/"
I0611 14:42:55.544132   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.544446   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/"
I0611 14:42:55.552191   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.552615   10461 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-2xvjb/test-mhc-tzzqz/test-mhc-machine-dwql6/"
I0611 14:42:55.567249   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-gs5kd" "namespace"="test-mhc-2xvjb" "descendants"="Worker machines: test-mhc-machine-dwql6" "indirect descendants count"=1
I0611 14:42:55.570822   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-gs5kd" "namespace"="test-mhc-2xvjb" "descendants"="Worker machines: test-mhc-machine-dwql6" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0611 14:42:55.571382   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tzzqz" "namespace"="test-mhc-2xvjb" 
I0611 14:42:55.719206   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" "creating"=1 "need"=1
I0611 14:42:55.719258   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" 
I0611 14:42:55.729934   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-r8htk-88f6w\"" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" 
I0611 14:42:55.806217   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:42:55.824435   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0611 14:42:55.844267   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
E0611 14:42:56.391195   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
E0611 14:42:56.402738   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hcrwl/test-cluster-8l7bl"
I0611 14:42:56.844492   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:42:57.391771   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-gs5kd" "machine"="test-mhc-machine-dwql6" "namespace"="test-mhc-2xvjb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mhhz4"}
E0611 14:42:57.442374   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dwql6\" not found" "controller"="machine" "name"="test-mhc-machine-dwql6" "namespace"="test-mhc-2xvjb"
I0611 14:42:57.845322   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:42:58.459756   10461 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" 
I0611 14:42:58.460071   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:42:58.463044   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:42:58.463864   10461 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" 
I0611 14:42:58.477260   10461 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
... skipping 5 lines ...
I0611 14:42:58.497607   10461 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:42:58.497648   10461 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:42:58.846409   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:42:59.497507   10461 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:42:59.497558   10461 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.000710   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.001170   10461 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-zttsw/test-mhc-fw8rv/mhc-ms-r8htk-88f6w/"
I0611 14:43:00.009366   10461 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.019942   10461 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.019992   10461 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.021957   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.022267   10461 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-zttsw/test-mhc-fw8rv/mhc-ms-r8htk-88f6w/"
I0611 14:43:00.026160   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.026494   10461 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-zttsw/test-mhc-fw8rv/mhc-ms-r8htk-88f6w/"
I0611 14:43:00.026900   10461 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.047584   10461 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.047627   10461 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.072483   10461 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-hps8f" "namespace"="test-mhc-zttsw" "count"=1
I0611 14:43:00.072543   10461 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-hps8f" "namespace"="test-mhc-zttsw" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-r8htk"
I0611 14:43:00.075613   10461 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-r8htk" "namespace"="test-mhc-zttsw" "machine"="mhc-ms-r8htk-88f6w"
I0611 14:43:00.078622   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hps8f" "namespace"="test-mhc-zttsw" "descendants"="Machine sets: mhc-ms-r8htk;Worker machines: mhc-ms-r8htk-88f6w" "indirect descendants count"=1
I0611 14:43:00.079445   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fw8rv" "namespace"="test-mhc-zttsw" 
I0611 14:43:00.082743   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hps8f" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" "cause"="cluster is being deleted" "node"=null
I0611 14:43:00.085077   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hps8f" "namespace"="test-mhc-zttsw" "descendants"="Worker machines: mhc-ms-r8htk-88f6w" "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
I0611 14:43:00.133472   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hps8f" "machine"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw" "cause"="cluster is being deleted" "node"=null
E0611 14:43:00.182417   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-r8htk-88f6w\" not found" "controller"="machine" "name"="mhc-ms-r8htk-88f6w" "namespace"="test-mhc-zttsw"
I0611 14:43:00.255303   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
inframachine created: test-mhc-machine-infra-j9c49
I0611 14:43:00.288028   10461 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-wwbs8
I0611 14:43:00.313244   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.324266   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
... skipping 129 lines ...
I0611 14:43:00.575729   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.577473   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.579288   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.581352   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.583195   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.585104   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
E0611 14:43:00.585285   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-2xvjb/test-cluster-gs5kd"
I0611 14:43:00.591535   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.593753   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.595686   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.597530   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.599274   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:00.601097   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
... skipping 276 lines ...
I0611 14:43:01.186617   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.188370   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.190203   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.190848   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.192692   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.194484   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
E0611 14:43:01.194740   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
node created: test-mhc-node-kh4h5
E0611 14:43:01.203674   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kh4h5, got []"  "node"="test-mhc-node-kh4h5"
E0611 14:43:01.203673   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kh4h5, got []"  "node"="test-mhc-node-kh4h5"
I0611 14:43:01.228259   10461 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-wwbs8" "target"="test-mhc-grk7n/test-mhc-mtvgj/test-mhc-machine-wwbs8/"
I0611 14:43:01.240058   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.259187   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.266946   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.270886   10461 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-wwbs8" "target"="test-mhc-grk7n/test-mhc-mtvgj/test-mhc-machine-wwbs8/test-mhc-node-kh4h5"
I0611 14:43:01.289492   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
Cleaning up nodes, machines and infra machines.
I0611 14:43:01.301840   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.311189   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.321683   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mtvgj" "namespace"="test-mhc-grk7n" 
I0611 14:43:01.326993   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-47hhv" "namespace"="test-mhc-grk7n" "descendants"="Worker machines: test-mhc-machine-wwbs8" "indirect descendants count"=1
... skipping 305 lines ...
I0611 14:43:02.237922   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.239672   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.241407   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.243146   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.249306   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.251274   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
E0611 14:43:02.251633   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wwbs8\" not found" "controller"="machine" "name"="test-mhc-machine-wwbs8" "namespace"="test-mhc-grk7n"
I0611 14:43:02.253123   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.254913   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.256905   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.258702   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.260531   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:02.262286   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
... skipping 523 lines ...
I0611 14:43:03.256162   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.258254   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.259251   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.259892   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.262155   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.263287   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
E0611 14:43:03.263518   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
I0611 14:43:03.267152   10461 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-ls9vf" "target"="test-mhc-g7cvt/test-mhc-rpl59/test-mhc-machine-ls9vf/"
I0611 14:43:03.277848   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
E0611 14:43:03.300884   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8d67n, got []"  "node"="test-mhc-node-8d67n"
E0611 14:43:03.300898   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8d67n, got []"  "node"="test-mhc-node-8d67n"
E0611 14:43:03.300952   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8d67n, got []"  "node"="test-mhc-node-8d67n"
node created: test-mhc-node-8d67n
I0611 14:43:03.309564   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.331653   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.334436   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.343507   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.347285   10461 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-ls9vf" "target"="test-mhc-g7cvt/test-mhc-rpl59/test-mhc-machine-ls9vf/test-mhc-node-8d67n"
I0611 14:43:03.367635   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.378167   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.399895   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
Cleaning up nodes, machines and infra machines.
I0611 14:43:03.414865   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
I0611 14:43:03.420060   10461 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-ls9vf" "target"="test-mhc-g7cvt/test-mhc-rpl59/test-mhc-machine-ls9vf/"
I0611 14:43:03.427603   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dgjjt" "namespace"="test-mhc-g7cvt" "descendants"="Worker machines: test-mhc-machine-ls9vf" "indirect descendants count"=1
I0611 14:43:03.431164   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dgjjt" "namespace"="test-mhc-g7cvt" "descendants"="Worker machines: test-mhc-machine-ls9vf" "indirect descendants count"=1
E0611 14:43:03.439280   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-rpl59\" not found" "controller"="machinehealthcheck" "name"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt"
--- PASS: TestMachineHealthCheck_Reconcile (40.43s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.17s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (0.93s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.24s)
... 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.24s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.11s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0611 14:43:03.442594   10461 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
E0611 14:43:03.444004   10461 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
E0611 14:43:03.445848   10461 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0611 14:43:03.446121   10461 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
E0611 14:43:03.446521   10461 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
I0611 14:43:03.449311   10461 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0611 14:43:03.449809   10461 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0611 14:43:03.451269   10461 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
E0611 14:43:03.458733   10461 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
E0611 14:43:03.460173   10461 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 82 lines ...
I0611 14:43:03.472556   10461 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"
•I0611 14:43:03.473998   10461 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"
I0611 14:43:03.474725   10461 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"
I0611 14:43:03.475386   10461 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0611 14:43:03.475460   10461 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0611 14:43:03.476008   10461 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0611 14:43:03.477257   10461 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" 
•I0611 14:43:03.559961   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-pl962" "namespace"="ms-test" "creating"=2 "need"=2
I0611 14:43:03.560004   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-pl962" "namespace"="ms-test" 
I0611 14:43:03.575550   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-pl962-6mwbg\"" "machineset"="ms-pl962" "namespace"="ms-test" 
I0611 14:43:03.575620   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-pl962" "namespace"="ms-test" 
I0611 14:43:03.589794   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-pl962-xtv5b\"" "machineset"="ms-pl962" "namespace"="ms-test" 
I0611 14:43:03.702955   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-pl962" "namespace"="ms-test" "creating"=1 "need"=2
I0611 14:43:03.703005   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-pl962" "namespace"="ms-test" 
I0611 14:43:03.719159   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-pl962-cv5l7\"" "machineset"="ms-pl962" "namespace"="ms-test" 
E0611 14:43:03.810451   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.810451   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.810506   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.913663   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.913717   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.913663   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.913750   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.913663   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.913782   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-cv5l7-7zn4f, got []"  "node"="ms-pl962-cv5l7-7zn4f"
E0611 14:43:03.941384   10461 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-pl962-cv5l7-7zn4f for machine ms-test/ms-pl962-cv5l7: the cache is not started, can not read objects" "machineset"="ms-pl962" "namespace"="ms-test" 
E0611 14:43:03.947733   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.947736   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.948394   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.951303   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.951392   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.951678   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.951741   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.952073   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
E0611 14:43:03.952106   10461 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-pl962-xtv5b-lgj8v, got []"  "node"="ms-pl962-xtv5b-lgj8v"
I0611 14:43:04.071878   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-pl962-cv5l7,ms-pl962-xtv5b" "indirect descendants count"=2
•I0611 14:43:04.076635   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-pl962-cv5l7,ms-pl962-xtv5b" "indirect descendants count"=2
•E0611 14:43:04.194735   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-tf4gq\" not found" "controller"="cluster" "name"="test1-tf4gq" "namespace"="default"
I0611 14:43:04.264022   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dgjjt" "machine"="test-mhc-machine-ls9vf" "namespace"="test-mhc-g7cvt" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8d67n"}
E0611 14:43:04.296657   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ls9vf\" not found" "controller"="machine" "name"="test-mhc-machine-ls9vf" "namespace"="test-mhc-g7cvt"
I0611 14:43:04.439567   10461 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpl59" "namespace"="test-mhc-g7cvt" 
E0611 14:43:05.214420   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zttsw/test-cluster-hps8f"
•I0611 14:43:05.323672   10461 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-586t8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0611 14:43:05.440913   10461 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-586t8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0611 14:43:05.445174   10461 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-586t8" "namespace"="default"
E0611 14:43:06.458074   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-586t8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-586t8" "namespace"="default"
•E0611 14:43:07.470386   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-grk7n/test-cluster-47hhv"
E0611 14:43:07.481567   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-lzvvk\" not found" "controller"="cluster" "name"="test3-lzvvk" "namespace"="default"
E0611 14:43:08.482305   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-586t8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-586t8" "namespace"="default"
E0611 14:43:09.509126   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-g7cvt/test-cluster-dgjjt"
E0611 14:43:09.509180   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-586t8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-586t8" "namespace"="default"
•I0611 14:43:10.509651   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-pl962-cv5l7,ms-pl962-xtv5b" "indirect descendants count"=2
E0611 14:43:10.513569   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dqbtn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dqbtn" "namespace"="default"
E0611 14:43:11.435672   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-mzsks\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-mzsks" "namespace"="test-mhc-zgxv9"
E0611 14:43:11.514380   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-586t8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-586t8" "namespace"="default"
E0611 14:43:12.524345   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dqbtn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dqbtn" "namespace"="default"
•E0611 14:43:13.503888   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-6d6jg\" for machine \"test-mhc-machine-b9c9w\" in namespace \"test-mhc-zgxv9\": Cluster.cluster.x-k8s.io \"test-cluster-6d6jg\" not found" "controller"="machine" "name"="test-mhc-machine-b9c9w" "namespace"="test-mhc-zgxv9"
E0611 14:43:13.525053   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-586t8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-586t8" "namespace"="default"
E0611 14:43:14.525895   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dqbtn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dqbtn" "namespace"="default"
E0611 14:43:15.536259   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-586t8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-586t8" "namespace"="default"
I0611 14:43:15.613023   10461 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-g6lqq" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0611 14:43:15.633300   10461 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-g6lqq" "namespace"="default" 
E0611 14:43:15.658896   10461 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-g6lqq" "namespace"="default"
E0611 14:43:16.537246   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dqbtn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dqbtn" "namespace"="default"
I0611 14:43:16.678067   10461 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-g6lqq" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0611 14:43:16.678352   10461 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-g6lqq" "namespace"="default" "noderef"="id-node-1"
E0611 14:43:16.690465   10461 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-g6lqq" "namespace"="default"
I0611 14:43:17.537871   10461 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-pl962-cv5l7,ms-pl962-xtv5b" "indirect descendants count"=2
E0611 14:43:17.543548   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-586t8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-586t8" "namespace"="default"

------------------------------
• [SLOW TEST:5.035 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 2 lines ...
I0611 14:43:17.649808   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0611 14:43:17.649849   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.658670   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-nb5rk-6657c7fddb-hdn24\"" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.658745   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.668267   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-nb5rk-6657c7fddb-mqn2j\"" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.690992   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-fl9tc" "machine"="test6-g6lqq" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"b381fe9a-fc9e-4ba9-8f04-713565551f35","apiVersion":"v1"}
E0611 14:43:17.709596   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-g6lqq\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-g6lqq" "namespace"="default"
I0611 14:43:17.743237   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0611 14:43:17.743278   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.755308   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-nb5rk-6657c7fddb-r7xcv\"" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.755390   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.771562   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-nb5rk-6657c7fddb-mh4r7\"" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.852589   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0611 14:43:17.852631   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.862865   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb5rk-6657c7fddb-npgd2\"" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" 
I0611 14:43:17.958639   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0611 14:43:17.958732   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" 
I0611 14:43:17.970829   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb5rk-cdfc6fd6c-8krwr\"" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" 
E0611 14:43:18.087507   10461 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-nb5rk-cdfc6fd6c-8krwr-q9kf5 for machine md-test/md-nb5rk-cdfc6fd6c-8krwr: the cache is not started, can not read objects" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" 
I0611 14:43:18.114294   10461 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0611 14:43:18.114330   10461 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0611 14:43:18.124490   10461 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "machine"="md-nb5rk-6657c7fddb-r7xcv"
I0611 14:43:18.235143   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0611 14:43:18.235200   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" 
I0611 14:43:18.245574   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb5rk-cdfc6fd6c-c4mg8\"" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" 
I0611 14:43:18.435124   10461 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0611 14:43:18.435166   10461 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0611 14:43:18.442373   10461 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "machine"="md-nb5rk-6657c7fddb-mh4r7"
I0611 14:43:18.463907   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0611 14:43:18.463982   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" 
I0611 14:43:18.475077   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb5rk-cdfc6fd6c-htjh5\"" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" 
E0611 14:43:18.544365   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dqbtn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dqbtn" "namespace"="default"
I0611 14:43:18.670021   10461 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0611 14:43:18.670061   10461 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0611 14:43:18.673964   10461 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb5rk-6657c7fddb" "namespace"="md-test" "machine"="md-nb5rk-6657c7fddb-npgd2"
I0611 14:43:18.740866   10461 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-fl9tc" "machine"="test6-g6lqq" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"b381fe9a-fc9e-4ba9-8f04-713565551f35","apiVersion":"v1"}
E0611 14:43:18.741677   10461 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-g6lqq\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-g6lqq" "namespace"="default"
I0611 14:43:18.800333   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0611 14:43:18.800372   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-nb5rk-74d45c49c5" "namespace"="md-test" 
I0611 14:43:18.810941   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb5rk-74d45c49c5-9kbf8\"" "machineset"="md-nb5rk-74d45c49c5" "namespace"="md-test" 
I0611 14:43:18.934807   10461 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0611 14:43:18.934846   10461 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0611 14:43:18.939105   10461 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "machine"="md-nb5rk-cdfc6fd6c-c4mg8"
... skipping 3 lines ...
I0611 14:43:19.164403   10461 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0611 14:43:19.164438   10461 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0611 14:43:19.169342   10461 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb5rk-cdfc6fd6c" "namespace"="md-test" "machine"="md-nb5rk-cdfc6fd6c-htjh5"
I0611 14:43:19.283305   10461 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb5rk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0611 14:43:19.283375   10461 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nb5rk-74d45c49c5" "namespace"="md-test" 
I0611 14:43:19.294412   10461 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb5rk-74d45c49c5-nrjwd\"" "machineset"="md-nb5rk-74d45c49c5" "namespace"="md-test" 
E0611 14:43:19.539162   10461 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
•

Ran 16 of 16 Specs in 16.081 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.08s)
PASS
Tearing down test suite
E0611 14:43:19.542680   10461 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0611 14:43:19.542721   10461 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-765296897/tls.crt: no such file or directory"  
E0611 14:43:19.542742   10461 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0611 14:43:19.542762   10461 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-765296897/tls.crt: no such file or directory"  
I0611 14:43:19.543275   10461 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0611 14:43:19.543301   10461 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0611 14:43:19.543303   10461 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0611 14:43:19.543330   10461 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0611 14:43:19.543356   10461 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0611 14:43:19.543371   10461 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0611 14:43:19.543383   10461 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0611 14:43:19.578986   10461 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:32805/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1238&timeout=10s&timeoutSeconds=393&watch=true: dial tcp 127.0.0.1:32805: connect: connection refused
E0611 14:43:19.579448   10461 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:32805/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1238&timeout=10s&timeoutSeconds=579&watch=true: dial tcp 127.0.0.1:32805: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	73.029s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0611 14:42:22.665744   10921 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0611 14:42:22.683133   10921 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0611 14:42:22.983768   10921 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0611 14:42:22.983845   10921 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0611 14:42:22.983919   10921 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0611 14:42:23.517603   10921 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0611 14:42:25.576952   10921 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-skkcb/test-cluster"
•E0611 14:42:26.021732   10921 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-zhqrr/test-cluster"
•E0611 14:42:26.556575   10921 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:43381/?timeout=50ms: dial tcp 127.0.0.1:43381: connect: connection refused"  "cluster"="cluster-cache-test-bpcc7/test-cluster"
•I0611 14:42:26.677819   10921 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0611 14:42:26.723699   10921 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:45087/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:45087: connect: connection refused


Ran 5 of 5 Specs in 17.850 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (17.85s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	18.016s
?   	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
I0611 14:42:33.440976   11622 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
E0611 14:42:33.442476   11622 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
I0611 14:42:33.443072   11622 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0611 14:42:33.443220   11622 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
I0611 14:42:49.635443   11622 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
I0611 14:42:49.635571   11622 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: 1654958539
Will run 1 of 1 specs

E0611 14:42:49.658881   11622 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-h5xkj1\" not found" "kubeadmControlPlane"="kcp-foo-h5xkj1" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.020 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0611 14:42:49.660526   11622 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-8ne2ij" "kubeadmControlPlane"="kcp-foo-8ne2ij" "namespace"="test" 
I0611 14:42:52.313761   11622 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-8ne2ij" "kubeadmControlPlane"="kcp-foo-8ne2ij" "namespace"="test" "needRollout"=["kcp-foo-8ne2ij-5jhzn"]
I0611 14:42:52.313949   11622 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-8ne2ij" "kubeadmControlPlane"="kcp-foo-8ne2ij" "namespace"="test" "failures"="[machine kcp-foo-8ne2ij-v67jj does not have APIServerPodHealthy condition, machine kcp-foo-8ne2ij-v67jj does not have ControllerManagerPodHealthy condition, machine kcp-foo-8ne2ij-v67jj does not have SchedulerPodHealthy condition, machine kcp-foo-8ne2ij-v67jj does not have EtcdPodHealthy condition, machine kcp-foo-8ne2ij-v67jj does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (2.66s)
... skipping 60 lines ...
==================================
Random Seed: 1654958538
Will run 7 of 7 specs

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

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0611 14:42:31.070891   11564 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"  
E0611 14:42:39.393972   11564 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"  
E0611 14:42:48.379977   11564 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"  
E0611 14:42:59.510284   11564 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"  
E0611 14:43:15.983548   11564 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"  
E0611 14:43:28.992201   11564 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"  
E0611 14:43:46.639619   11564 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"  
E0611 14:44:07.562929   11564 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"  
E0611 14:44:38.579456   11564 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"  
E0611 14:45:23.736691   11564 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 383 lines ...
I0611 14:42:41.958861   11900 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0611 14:42:42.057994   11900 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0611 14:42:42.158377   11900 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0611 14:42:42.158463   11900 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0611 14:42:42.160120   11900 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0611 14:42:42.273501   11900 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-hh4jzu"} 
E0611 14:42:42.299351   11900 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"
•I0611 14:42:43.396413   11900 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-0lz37e"} 
E0611 14:42:43.453816   11900 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"
•E0611 14:42:44.502342   11900 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"
E0611 14:42:45.525247   11900 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"
•E0611 14:42:46.650860   11900 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"
•E0611 14:42:47.704206   11900 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"
E0611 14:42:48.722772   11900 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"
•I0611 14:42:48.729525   11900 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0611 14:42:48.729699   11900 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0611 14:42:48.729759   11900 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0611 14:42:48.729854   11900 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0611 14:42:48.729934   11900 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-169508731/tls.key: no such file or directory"  


Ran 5 of 5 Specs in 21.266 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (21.27s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	21.339s
?   	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
E0611 14:42:33.907239   12130 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.01s)
    --- 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.01s)
=== RUN   TestMachinePoolFinalizer
... skipping 95 lines ...
•I0611 14:42:44.924938   12130 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0611 14:42:44.952702   12130 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0611 14:42:44.955246   12130 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 11.009 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.01s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.212s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 210 lines ...
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39
  Should patch a clusterv1.Cluster
  /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:411
    updating both spec, status, and adding a condition [It]
    /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:550

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 24 lines ...
STEP: Creating a new patch helper
STEP: Updating the object spec
STEP: Updating the object status
STEP: Setting Ready condition
STEP: Patching the object
•I0611 14:43:10.100996   15073 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0611 14:43:10.101210   15073 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0611 14:43:10.101285   15073 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-458405154/tls.crt: no such file or directory"  



Summarizing 1 Failure:

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

Ran 14 of 14 Specs in 8.145 seconds
FAIL! -- 13 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestPatch (8.15s)
=== 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	8.239s
?   	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.013s
... 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.040s
FAIL
make: *** [Makefile:116: test] Error 1