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

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0728 23:39:07.791774    8515 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0728 23:39:07.792066    8515 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0728 23:39:07.793044    8515 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0728 23:39:07.793406    8515 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0728 23:39:07.793520    8515 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=44855
I0728 23:39:08.380159    8515 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" 
•E0728 23:39:08.390610    8515 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0728 23:39:08.390661    8515 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-323228438/tls.crt: no such file or directory"  
E0728 23:39:08.390680    8515 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0728 23:39:08.390698    8515 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-323228438/tls.crt: no such file or directory"  
I0728 23:39:08.390806    8515 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 14.732 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.73s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	61.263s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 310 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0728 23:38:40.762228   10495 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":{}}}
I0728 23:38:40.762246   10495 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
I0728 23:38:40.762285   10495 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0728 23:38:40.762326   10495 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0728 23:38:40.762369   10495 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0728 23:38:40.762420   10495 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2021/07/28 23:38:40 http: TLS handshake error from 127.0.0.1:40704: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0728 23:38:40.860213   10495 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"
I0728 23:38:40.870246   10495 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0728 23:38:40.902006   10495 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
I0728 23:38:40.904043   10495 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"
E0728 23:38:40.904355   10495 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
I0728 23:38:40.904741   10495 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
I0728 23:38:41.303689   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0728 23:38:41.404461   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0728 23:38:41.412113   10495 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-gj4zs" "namespace"="test-machine-watches-fnc5k" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0728 23:38:41.412200   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0728 23:38:41.521295   10495 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-gj4zs" "namespace"="test-machine-watches-fnc5k" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0728 23:38:41.521382   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0728 23:38:41.621885   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-gj4zs" "namespace"="test-machine-watches-fnc5k" "noderef"="node-1"
E0728 23:38:41.640118   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0728 23:38:41.640178   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0728 23:38:41.664779   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-gj4zs" "namespace"="test-machine-watches-fnc5k" "noderef"="node-1"
E0728 23:38:41.679126   10495 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-gj4zs\" in namespace \"test-machine-watches-fnc5k\", requeuing: requeue in 1s"  
E0728 23:38:41.692328   10495 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-gj4zs\" in namespace \"test-machine-watches-fnc5k\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-gj4zs\" in namespace \"test-machine-watches-fnc5k\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-gj4zs" "namespace"="test-machine-watches-fnc5k"
--- PASS: TestWatches (0.81s)
=== 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
I0728 23:38:41.812895   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-qzjls" "namespace"="test-machine-watches-fnc5k" "count"=1
I0728 23:38:41.812956   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-qzjls" "namespace"="test-machine-watches-fnc5k" "descendants"="Worker machines: machine-created-gj4zs" "indirect descendants count"=0
I0728 23:38:41.827685   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-qzjls" "namespace"="test-machine-watches-fnc5k" "count"=1
I0728 23:38:41.827829   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-qzjls" "namespace"="test-machine-watches-fnc5k" "descendants"="Worker machines: machine-created-gj4zs" "indirect descendants count"=0
I0728 23:38:42.692806   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-qzjls" "machine"="machine-created-gj4zs" "namespace"="test-machine-watches-fnc5k" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"6a761ad7-ffcd-4093-aa3d-61de538c761a","apiVersion":"v1"}
E0728 23:38:42.924378   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-gj4zs\" not found" "controller"="machine" "name"="machine-created-gj4zs" "namespace"="test-machine-watches-fnc5k"
E0728 23:38:43.979432   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-gkhxr\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-9ggb2\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-9ggb2: secrets \"machine-reconcile-9ggb2-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-gkhxr" "namespace"="default"
I0728 23:38:44.980034   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-9ggb2" "machine"="machine-created-gkhxr" "namespace"="default" "cause"="noderef is nil" "node"=null
I0728 23:38:45.012618   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-9ggb2" "machine"="machine-created-gkhxr" "namespace"="default" "cause"="noderef is nil" "node"=null
I0728 23:38:45.040366   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-9ggb2" "machine"="machine-created-gkhxr" "namespace"="default" "cause"="noderef is nil" "node"=null
E0728 23:38:45.085529   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-gkhxr\" not found" "controller"="machine" "name"="machine-created-gkhxr" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.37s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.37s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 4 lines ...
I0728 23:38:45.098614   10495 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"
I0728 23:38:45.098893   10495 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
I0728 23:38:45.105320   10495 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"
I0728 23:38:45.105448   10495 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
E0728 23:38:45.110039   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-9ggb2\" not found" "controller"="cluster" "name"="machine-reconcile-9ggb2" "namespace"="default"
I0728 23:38:45.110806   10495 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"
I0728 23:38:45.111755   10495 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.02s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.01s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s)
... skipping 120 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_up (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0728 23:38:45.331824   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q2hnt" "namespace"="test-mhc-kl56p" 
I0728 23:38:45.363637   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0728 23:38:45.364687   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-4kcqh\" not found"  "cluster"="test-mhc-kl56p/test-cluster-4kcqh"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0728 23:38:45.378386   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-q2hnt\" not found" "controller"="machinehealthcheck" "name"="test-mhc-q2hnt" "namespace"="test-mhc-kl56p"
=== 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
I0728 23:38:46.378722   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q2hnt" "namespace"="test-mhc-kl56p" 
I0728 23:38:46.378853   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7j95f" "namespace"="test-mhc-k788b" 
I0728 23:38:46.378885   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b7zv5" "namespace"="test-mhc-2ksgr" 
I0728 23:38:46.378911   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ss867" "namespace"="test-mhc-f88br" 
I0728 23:38:46.401633   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:38:46.527652   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ss867" "namespace"="test-mhc-f88br" 
I0728 23:38:46.593299   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ss867" "namespace"="test-mhc-f88br" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0728 23:38:46.601434   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-f88br/test-cluster-7sz9l"
E0728 23:38:46.602961   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-7sz9l\" not found" "controller"="cluster" "name"="test-cluster-7sz9l" "namespace"="test-mhc-f88br"
I0728 23:38:46.614287   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zzmzg" "namespace"="test-mhc-m9j8p" 
I0728 23:38:46.635134   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:38:46.651894   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zzmzg" "namespace"="test-mhc-m9j8p" 
E0728 23:38:46.719339   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-m9j8p/test-cluster-8tdd9"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0728 23:38:46.724301   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zzmzg" "namespace"="test-mhc-m9j8p" 
I0728 23:38:46.741692   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
inframachine created: test-mhc-machine-infra-p8vb5
machine created: test-mhc-machine-xbd74
I0728 23:38:46.771366   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:38:46.873900   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xbd74/"
node created: test-mhc-node-7kn4l
E0728 23:38:46.879074   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7kn4l, got []"  "node"="test-mhc-node-7kn4l"
E0728 23:38:46.879100   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-7kn4l"
inframachine created: test-mhc-machine-infra-fnzxd
machine created: test-mhc-machine-xgc7m
I0728 23:38:46.911577   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:46.929639   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:46.936085   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:46.937408   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
... skipping 59 lines ...
I0728 23:38:47.103032   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.105437   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.106503   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.107498   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.109611   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.113540   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.113903   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
I0728 23:38:47.146632   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.147266   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
I0728 23:38:47.152943   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.153527   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
I0728 23:38:47.164177   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.164611   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
I0728 23:38:47.179107   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.180045   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
I0728 23:38:47.192319   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.192904   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
node created: test-mhc-node-7b6kd
E0728 23:38:47.208685   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-7b6kd"
E0728 23:38:47.209016   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7b6kd, got []"  "node"="test-mhc-node-7b6kd"
I0728 23:38:47.221438   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.222041   10495 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-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
I0728 23:38:47.226643   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.227402   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt" "noderef"="test-mhc-node-7b6kd"
I0728 23:38:47.253682   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
Cleaning up nodes, machines and infra machines.
I0728 23:38:47.259196   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.262467   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.262952   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-f9ptt/test-mhc-6j75z/test-mhc-machine-xbd74/"
I0728 23:38:47.289680   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:47.290200   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-f9ptt/test-mhc-6j75z/test-mhc-machine-xbd74/"
I0728 23:38:47.291276   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-f9ptt/test-mhc-6j75z/test-mhc-machine-xgc7m/"
I0728 23:38:47.314327   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wtpsd" "machine"="test-mhc-machine-xbd74" "namespace"="test-mhc-f9ptt" "cause"="no control plane members" "node"={"name":"test-mhc-node-7kn4l"}
E0728 23:38:47.332683   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-f9ptt/test-cluster-wtpsd"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0728 23:38:47.395434   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xbd74\" not found" "controller"="machine" "name"="test-mhc-machine-xbd74" "namespace"="test-mhc-f9ptt"
E0728 23:38:47.468774   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6j75z\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt"
inframachine created: test-mhc-machine-infra-xckcl
machine created: test-mhc-machine-45d6b
E0728 23:38:47.618939   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-fnc5k/machine-reconcile-qzjls"
E0728 23:38:48.395924   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:38:48.469071   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6j75z" "namespace"="test-mhc-f9ptt" 
I0728 23:38:48.469171   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:48.487187   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:38:48.507595   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:48.508529   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:48.510603   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
... skipping 408 lines ...
I0728 23:38:49.399669   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.401458   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.404003   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.406547   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.407622   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.409361   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
E0728 23:38:49.414017   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:38:49.414086   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.414337   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-45d6b/"
I0728 23:38:49.425293   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.425662   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-45d6b/"
node created: test-mhc-node-gwfvg
E0728 23:38:49.506128   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gwfvg, got []"  "node"="test-mhc-node-gwfvg"
I0728 23:38:49.514019   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
inframachine created: test-mhc-machine-infra-dzvc7
machine created: test-mhc-machine-w2jkr
I0728 23:38:49.536186   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.551998   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:49.553481   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
... skipping 346 lines ...
I0728 23:38:50.463733   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.466144   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.468423   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.470543   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.471825   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.475477   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
E0728 23:38:50.476249   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:38:50.477548   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.481250   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.486349   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.489592   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.493352   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:50.495755   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
... skipping 342 lines ...
I0728 23:38:51.475832   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.479390   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.483836   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.484800   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.488178   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.490670   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
E0728 23:38:51.501390   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:38:51.502401   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.503030   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-w2jkr/"
I0728 23:38:51.514208   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.514732   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-w2jkr/"
node created: test-mhc-node-rbfcj
E0728 23:38:51.538973   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rbfcj, got []"  "node"="test-mhc-node-rbfcj"
I0728 23:38:51.545996   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
inframachine created: test-mhc-machine-infra-lmbgv
machine created: test-mhc-machine-qgdxj
I0728 23:38:51.566437   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.577066   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:51.579068   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
... skipping 301 lines ...
I0728 23:38:52.532533   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.535736   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.542284   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.545587   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.548534   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.553204   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
E0728 23:38:52.566383   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:38:52.567366   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.571724   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.577661   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.580370   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.583092   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:52.585719   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
... skipping 289 lines ...
I0728 23:38:53.568122   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.571160   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.574290   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.575957   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.577559   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.579206   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.579715   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-qgdxj/"
I0728 23:38:53.593860   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.594379   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-qgdxj/"
I0728 23:38:53.596252   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.596899   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-qgdxj/"
E0728 23:38:53.597372   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
node created: test-mhc-node-sl8hv
E0728 23:38:53.599930   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sl8hv, got []"  "node"="test-mhc-node-sl8hv"
I0728 23:38:53.608183   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.608732   10495 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-dzwz4/test-mhc-bxbzs/test-mhc-machine-qgdxj/test-mhc-node-sl8hv"
Cleaning up nodes, machines and infra machines.
I0728 23:38:53.620080   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.620628   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dzwz4/test-mhc-bxbzs/test-mhc-machine-qgdxj/"
Cleaning up nodes, machines and infra machines.
I0728 23:38:53.633630   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:53.634161   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dzwz4/test-mhc-bxbzs/test-mhc-machine-45d6b/"
I0728 23:38:53.660243   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-xnr49" "namespace"="test-mhc-dzwz4" "count"=2
I0728 23:38:53.660327   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xnr49" "namespace"="test-mhc-dzwz4" "descendants"="Worker machines: test-mhc-machine-45d6b,test-mhc-machine-w2jkr,test-mhc-machine-qgdxj" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0728 23:38:53.673380   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-xnr49" "namespace"="test-mhc-dzwz4" "count"=2
I0728 23:38:53.673450   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xnr49" "namespace"="test-mhc-dzwz4" "descendants"="Worker machines: test-mhc-machine-45d6b,test-mhc-machine-w2jkr,test-mhc-machine-qgdxj" "indirect descendants count"=1
inframachine created: test-mhc-machine-infra-g9gcz
I0728 23:38:53.825243   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dzwz4/test-mhc-bxbzs/test-mhc-machine-qgdxj/"
machine created: test-mhc-machine-gsxcl
E0728 23:38:53.839380   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-bxbzs\" not found" "controller"="machinehealthcheck" "name"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4"
I0728 23:38:54.597915   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xnr49" "machine"="test-mhc-machine-qgdxj" "namespace"="test-mhc-dzwz4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-sl8hv"}
E0728 23:38:54.643458   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qgdxj\" not found" "controller"="machine" "name"="test-mhc-machine-qgdxj" "namespace"="test-mhc-dzwz4"
I0728 23:38:54.839673   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:54.860530   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:38:54.887272   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bxbzs" "namespace"="test-mhc-dzwz4" 
I0728 23:38:54.887351   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:54.892458   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:54.913406   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:54.954478   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:55.035470   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:55.196578   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:55.517676   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:55.643956   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xnr49" "machine"="test-mhc-machine-w2jkr" "namespace"="test-mhc-dzwz4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-rbfcj"}
E0728 23:38:55.687143   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-w2jkr\" not found" "controller"="machine" "name"="test-mhc-machine-w2jkr" "namespace"="test-mhc-dzwz4"
I0728 23:38:56.158732   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:56.687749   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xnr49" "machine"="test-mhc-machine-45d6b" "namespace"="test-mhc-dzwz4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gwfvg"}
E0728 23:38:56.740368   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-45d6b\" not found" "controller"="machine" "name"="test-mhc-machine-45d6b" "namespace"="test-mhc-dzwz4"
I0728 23:38:57.446189   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
E0728 23:38:57.740787   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
E0728 23:38:58.689697   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-dzwz4/test-cluster-xnr49"
I0728 23:38:58.756805   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:58.759878   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
E0728 23:38:58.761462   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
E0728 23:38:58.783651   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8j9qd, got []"  "node"="test-mhc-node-8j9qd"
node created: test-mhc-node-8j9qd
I0728 23:38:58.799625   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
inframachine created: test-mhc-machine-infra-8mghb
machine created: test-mhc-machine-6w76c
I0728 23:38:58.819263   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:58.837884   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
... skipping 6 lines ...
I0728 23:38:59.776247   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:59.786215   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:59.800968   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:59.809314   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:59.822138   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:59.830479   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
E0728 23:38:59.838198   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:38:59.871854   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
node created: test-mhc-node-4n6d7
E0728 23:38:59.927122   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4n6d7, got []"  "node"="test-mhc-node-4n6d7"
I0728 23:38:59.934264   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
inframachine created: test-mhc-machine-infra-86ddj
I0728 23:38:59.945956   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
machine created: test-mhc-machine-lccrc
I0728 23:38:59.954610   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:38:59.972189   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
... skipping 6 lines ...
I0728 23:39:00.900375   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:39:00.910943   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:39:00.914427   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:39:00.934902   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:39:00.960068   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:39:00.969617   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
E0728 23:39:00.970926   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-l7rrt, got []"  "node"="test-mhc-node-l7rrt"
node created: test-mhc-node-l7rrt
I0728 23:39:00.976218   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:39:00.983477   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
Cleaning up nodes, machines and infra machines.
I0728 23:39:00.997276   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
E0728 23:39:01.027153   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-lccrc\" in namespace \"test-mhc-9kbmm\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-lccrc" "namespace"="test-mhc-9kbmm"
Cleaning up nodes, machines and infra machines.
I0728 23:39:01.051122   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cdlxr" "namespace"="test-mhc-9kbmm" "count"=3
I0728 23:39:01.051213   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cdlxr" "namespace"="test-mhc-9kbmm" "descendants"="Worker machines: test-mhc-machine-gsxcl,test-mhc-machine-6w76c,test-mhc-machine-lccrc" "indirect descendants count"=0
I0728 23:39:01.057371   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cdlxr" "namespace"="test-mhc-9kbmm" "count"=3
I0728 23:39:01.057439   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cdlxr" "namespace"="test-mhc-9kbmm" "descendants"="Worker machines: test-mhc-machine-gsxcl,test-mhc-machine-6w76c,test-mhc-machine-lccrc" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
inframachine created: test-mhc-machine-infra-s25v6
machine created: test-mhc-machine-p8krg
I0728 23:39:01.237897   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:01.295986   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:39:01.420122   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl5c9" "namespace"="test-mhc-9kbmm" 
I0728 23:39:01.420196   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:02.027708   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cdlxr" "machine"="test-mhc-machine-6w76c" "namespace"="test-mhc-9kbmm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4n6d7"}
E0728 23:39:02.072547   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6w76c\" not found" "controller"="machine" "name"="test-mhc-machine-6w76c" "namespace"="test-mhc-9kbmm"
I0728 23:39:03.073078   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cdlxr" "machine"="test-mhc-machine-lccrc" "namespace"="test-mhc-9kbmm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-l7rrt"}
E0728 23:39:03.122021   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lccrc\" not found" "controller"="machine" "name"="test-mhc-machine-lccrc" "namespace"="test-mhc-9kbmm"
I0728 23:39:04.122691   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cdlxr" "machine"="test-mhc-machine-gsxcl" "namespace"="test-mhc-9kbmm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8j9qd"}
E0728 23:39:04.175701   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gsxcl\" not found" "controller"="machine" "name"="test-mhc-machine-gsxcl" "namespace"="test-mhc-9kbmm"
I0728 23:39:05.194483   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:05.197997   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
E0728 23:39:05.199028   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
E0728 23:39:05.225067   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xxkhl, got []"  "node"="test-mhc-node-xxkhl"
E0728 23:39:05.225066   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xxkhl, got []"  "node"="test-mhc-node-xxkhl"
node created: test-mhc-node-xxkhl
I0728 23:39:05.231723   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
inframachine created: test-mhc-machine-infra-tctcs
machine created: test-mhc-machine-wpnf9
I0728 23:39:05.247443   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:05.255770   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
E0728 23:39:06.068455   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9kbmm/test-cluster-cdlxr"
I0728 23:39:06.212672   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.218136   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.237989   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.247890   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.258623   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.271213   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.288066   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.304629   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.312483   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.319043   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.347040   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
node created: test-mhc-node-4952c
E0728 23:39:06.353964   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4952c, got []"  "node"="test-mhc-node-4952c"
I0728 23:39:06.355393   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-wpnf9" "namespace"="test-mhc-kx6gj" "noderef"="test-mhc-node-4952c"
E0728 23:39:06.360090   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4952c, got []"  "node"="test-mhc-node-4952c"
E0728 23:39:06.360138   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4952c, got []"  "node"="test-mhc-node-4952c"
I0728 23:39:06.363970   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
inframachine created: test-mhc-machine-infra-kz469
I0728 23:39:06.386252   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
machine created: test-mhc-machine-76jt5
I0728 23:39:06.393422   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.400190   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
... skipping 4 lines ...
Cleaning up nodes, machines and infra machines.
I0728 23:39:06.600523   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.606383   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
Cleaning up nodes, machines and infra machines.
I0728 23:39:06.627120   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.630244   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:06.632678   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kx6gj/test-mhc-86bkc/test-mhc-machine-p8krg/"
I0728 23:39:06.637949   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-j9wjw" "machine"="test-mhc-machine-76jt5" "namespace"="test-mhc-kx6gj" "cause"="noderef is nil" "node"=null
I0728 23:39:06.718650   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-j9wjw" "namespace"="test-mhc-kx6gj" "count"=3
I0728 23:39:06.718743   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j9wjw" "namespace"="test-mhc-kx6gj" "descendants"="Worker machines: test-mhc-machine-p8krg,test-mhc-machine-wpnf9,test-mhc-machine-76jt5" "indirect descendants count"=0
I0728 23:39:06.724137   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-j9wjw" "namespace"="test-mhc-kx6gj" "count"=3
I0728 23:39:06.724190   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j9wjw" "namespace"="test-mhc-kx6gj" "descendants"="Worker machines: test-mhc-machine-76jt5,test-mhc-machine-p8krg,test-mhc-machine-wpnf9" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
E0728 23:39:06.741210   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-76jt5\" not found" "controller"="machine" "name"="test-mhc-machine-76jt5" "namespace"="test-mhc-kx6gj"
inframachine created: test-mhc-machine-infra-4rhs5
machine created: test-mhc-machine-xjjzr
E0728 23:39:06.808824   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-86bkc\" not found" "controller"="machinehealthcheck" "name"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj"
I0728 23:39:07.741804   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-j9wjw" "machine"="test-mhc-machine-p8krg" "namespace"="test-mhc-kx6gj" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xxkhl"}
E0728 23:39:07.790238   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-p8krg\" not found" "controller"="machine" "name"="test-mhc-machine-p8krg" "namespace"="test-mhc-kx6gj"
I0728 23:39:07.809201   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:07.823172   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:39:07.963224   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86bkc" "namespace"="test-mhc-kx6gj" 
I0728 23:39:07.963309   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:07.964315   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:07.966405   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
... skipping 400 lines ...
I0728 23:39:08.832881   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.837705   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.839636   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.841584   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.843388   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.845206   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
E0728 23:39:08.846128   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wpnf9\" not found" "controller"="machine" "name"="test-mhc-machine-wpnf9" "namespace"="test-mhc-kx6gj"
I0728 23:39:08.847099   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.848892   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.851011   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.854666   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.856546   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:08.858297   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
... skipping 452 lines ...
I0728 23:39:09.859411   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.861024   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.861813   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.864533   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.866294   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.867996   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
E0728 23:39:09.869192   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:39:09.869726   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.869958   10495 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-rpcqq/test-mhc-f5bf2/test-mhc-machine-xjjzr/"
I0728 23:39:09.881780   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.882113   10495 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-rpcqq/test-mhc-f5bf2/test-mhc-machine-xjjzr/"
E0728 23:39:09.929251   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-926tt, got []"  "node"="test-mhc-node-926tt"
node created: test-mhc-node-926tt
E0728 23:39:09.929601   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-926tt, got []"  "node"="test-mhc-node-926tt"
I0728 23:39:09.939027   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.959246   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.970458   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.970900   10495 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-rpcqq/test-mhc-f5bf2/test-mhc-machine-xjjzr/test-mhc-node-926tt"
I0728 23:39:09.991940   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:09.992356   10495 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-rpcqq/test-mhc-f5bf2/test-mhc-machine-xjjzr/test-mhc-node-926tt"
Cleaning up nodes, machines and infra machines.
I0728 23:39:10.002604   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:10.002974   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rpcqq/test-mhc-f5bf2/test-mhc-machine-xjjzr/"
I0728 23:39:10.025474   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8bxdx" "namespace"="test-mhc-rpcqq" "descendants"="Worker machines: test-mhc-machine-xjjzr" "indirect descendants count"=1
I0728 23:39:10.035655   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8bxdx" "namespace"="test-mhc-rpcqq" "descendants"="Worker machines: test-mhc-machine-xjjzr" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0728 23:39:10.141105   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" "creating"=1 "need"=1
I0728 23:39:10.141154   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:10.152422   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-zqx4h-n9mfl\"" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:10.175728   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f5bf2" "namespace"="test-mhc-rpcqq" 
I0728 23:39:10.233875   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:10.251622   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 23:39:10.257786   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:10.370603   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:10.371366   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:10.870561   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8bxdx" "machine"="test-mhc-machine-xjjzr" "namespace"="test-mhc-rpcqq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-926tt"}
E0728 23:39:10.911438   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xjjzr\" not found" "controller"="machine" "name"="test-mhc-machine-xjjzr" "namespace"="test-mhc-rpcqq"
I0728 23:39:11.370761   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
E0728 23:39:11.755425   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kx6gj/test-cluster-j9wjw"
I0728 23:39:11.923816   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.924565   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.933833   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.934376   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.943032   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.943082   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
... skipping 3 lines ...
I0728 23:39:11.963905   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.966400   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.966442   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.974977   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:11.975011   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.371863   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.372303   10495 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-56hgx/test-mhc-gmq9k/mhc-ms-zqx4h-n9mfl/"
I0728 23:39:12.381161   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.385734   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.385778   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.387369   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.387693   10495 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-56hgx/test-mhc-gmq9k/mhc-ms-zqx4h-n9mfl/"
I0728 23:39:12.396007   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.396463   10495 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-56hgx/test-mhc-gmq9k/mhc-ms-zqx4h-n9mfl/"
I0728 23:39:12.397479   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.405984   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.406041   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.471782   10495 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" "machine"="mhc-ms-zqx4h-n9mfl"
I0728 23:39:12.471904   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-vq6c2" "namespace"="test-mhc-56hgx" "count"=1
I0728 23:39:12.471960   10495 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-vq6c2" "namespace"="test-mhc-56hgx" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-zqx4h"
I0728 23:39:12.482347   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.482744   10495 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-56hgx/test-mhc-gmq9k/mhc-ms-zqx4h-n9mfl/"
I0728 23:39:12.483803   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vq6c2" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" "cause"="cluster is being deleted" "node"=null
I0728 23:39:12.485630   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gmq9k" "namespace"="test-mhc-56hgx" 
I0728 23:39:12.488953   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vq6c2" "namespace"="test-mhc-56hgx" "descendants"="Machine sets: mhc-ms-zqx4h;Worker machines: mhc-ms-zqx4h-n9mfl" "indirect descendants count"=1
I0728 23:39:12.494065   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vq6c2" "namespace"="test-mhc-56hgx" "descendants"="Worker machines: mhc-ms-zqx4h-n9mfl" "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
E0728 23:39:12.516270   10495 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-zqx4h\" not found" "machineset"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx" 
E0728 23:39:12.516355   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-zqx4h\" not found" "controller"="machineset" "name"="mhc-ms-zqx4h" "namespace"="test-mhc-56hgx"
I0728 23:39:12.543602   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vq6c2" "machine"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx" "cause"="cluster is being deleted" "node"=null
E0728 23:39:12.577305   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-zqx4h-n9mfl\" not found" "controller"="machine" "name"="mhc-ms-zqx4h-n9mfl" "namespace"="test-mhc-56hgx"
I0728 23:39:12.599409   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
inframachine created: test-mhc-machine-infra-7zcsc
I0728 23:39:12.622971   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-bvlt7
I0728 23:39:12.650017   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:12.659226   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
... skipping 422 lines ...
I0728 23:39:13.580997   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.583465   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.585320   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.587210   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.587849   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.593761   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
E0728 23:39:13.635105   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-54smj, got []"  "node"="test-mhc-node-54smj"
E0728 23:39:13.635105   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-54smj, got []"  "node"="test-mhc-node-54smj"
node created: test-mhc-node-54smj
E0728 23:39:13.635164   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-54smj, got []"  "node"="test-mhc-node-54smj"
I0728 23:39:13.638408   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-bvlt7" "namespace"="test-mhc-jrxrm" "noderef"="test-mhc-node-54smj"
I0728 23:39:13.646169   10495 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-bvlt7" "target"="test-mhc-jrxrm/test-mhc-2l5tq/test-mhc-machine-bvlt7/"
I0728 23:39:13.857155   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.885533   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.893256   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.897026   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.906432   10495 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-bvlt7" "target"="test-mhc-jrxrm/test-mhc-2l5tq/test-mhc-machine-bvlt7/test-mhc-node-54smj"
I0728 23:39:13.942585   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
Cleaning up nodes, machines and infra machines.
I0728 23:39:13.955015   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.959388   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.962448   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mn6m5" "machine"="test-mhc-machine-bvlt7" "namespace"="test-mhc-jrxrm" "cause"="no control plane members" "node"={"kind":"Node","name":"test-mhc-node-54smj","uid":"c37e8741-35f5-498d-aa1c-b8bd658349b4","apiVersion":"v1"}
I0728 23:39:13.964390   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.973063   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
I0728 23:39:13.981337   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mn6m5" "namespace"="test-mhc-jrxrm" "count"=1
I0728 23:39:13.981434   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mn6m5" "namespace"="test-mhc-jrxrm" "descendants"="Worker machines: test-mhc-machine-bvlt7" "indirect descendants count"=0
I0728 23:39:13.993206   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mn6m5" "namespace"="test-mhc-jrxrm" "count"=1
I0728 23:39:13.993267   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mn6m5" "namespace"="test-mhc-jrxrm" "descendants"="Worker machines: test-mhc-machine-bvlt7" "indirect descendants count"=0
I0728 23:39:13.994984   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2l5tq" "namespace"="test-mhc-jrxrm" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
E0728 23:39:14.041074   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-bvlt7\" not found" "controller"="machine" "name"="test-mhc-machine-bvlt7" "namespace"="test-mhc-jrxrm"
I0728 23:39:14.048266   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
inframachine created: test-mhc-machine-infra-f67vg
I0728 23:39:14.073476   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-rqzq7
I0728 23:39:14.192526   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:14.197066   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
... skipping 388 lines ...
I0728 23:39:15.061170   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.063045   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.065568   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.066258   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.067664   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.071697   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
E0728 23:39:15.073583   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
I0728 23:39:15.073674   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
E0728 23:39:15.076489   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rpcqq/test-cluster-8bxdx"
I0728 23:39:15.080079   10495 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-rqzq7" "target"="test-mhc-kx2fg/test-mhc-4lbt9/test-mhc-machine-rqzq7/"
node created: test-mhc-node-fjxq5
E0728 23:39:15.088027   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjxq5, got []"  "node"="test-mhc-node-fjxq5"
E0728 23:39:15.088241   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjxq5, got []"  "node"="test-mhc-node-fjxq5"
E0728 23:39:15.088432   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjxq5, got []"  "node"="test-mhc-node-fjxq5"
I0728 23:39:15.101647   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.123928   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.135869   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.139095   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.143348   10495 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-rqzq7" "target"="test-mhc-kx2fg/test-mhc-4lbt9/test-mhc-machine-rqzq7/test-mhc-node-fjxq5"
I0728 23:39:15.163714   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.170986   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.174388   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.203754   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
Cleaning up nodes, machines and infra machines.
I0728 23:39:15.208866   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.211338   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
I0728 23:39:15.222247   10495 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-rqzq7" "target"="test-mhc-kx2fg/test-mhc-4lbt9/test-mhc-machine-rqzq7/"
I0728 23:39:15.224183   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-thjjt" "namespace"="test-mhc-kx2fg" "descendants"="Worker machines: test-mhc-machine-rqzq7" "indirect descendants count"=1
I0728 23:39:15.229363   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-thjjt" "namespace"="test-mhc-kx2fg" "descendants"="Worker machines: test-mhc-machine-rqzq7" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (29.94s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.07s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.13s)
... skipping 12 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.51s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (1.23s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0728 23:39:15.242231   10495 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
E0728 23:39:15.244118   10495 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
E0728 23:39:15.248729   10495 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
E0728 23:39:15.249247   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4lbt9\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0728 23:39:15.257912   10495 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
E0728 23:39:15.258504   10495 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.01s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.01s)
... 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
I0728 23:39:15.262159   10495 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0728 23:39:15.263006   10495 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0728 23:39:15.265757   10495 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.01s)
=== 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
E0728 23:39:15.277048   10495 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
E0728 23:39:15.278974   10495 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 ...
I0728 23:39:15.312260   10495 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"
•I0728 23:39:15.315309   10495 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"
I0728 23:39:15.316418   10495 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"
I0728 23:39:15.317528   10495 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0728 23:39:15.317600   10495 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0728 23:39:15.318354   10495 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0728 23:39:15.320541   10495 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" 
••E0728 23:39:15.455396   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-7ct28\" not found" "controller"="cluster" "name"="test1-7ct28" "namespace"="default"
I0728 23:39:16.078028   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-thjjt" "machine"="test-mhc-machine-rqzq7" "namespace"="test-mhc-kx2fg" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-fjxq5"}
E0728 23:39:16.133414   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rqzq7\" not found" "controller"="machine" "name"="test-mhc-machine-rqzq7" "namespace"="test-mhc-kx2fg"
I0728 23:39:16.249763   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4lbt9" "namespace"="test-mhc-kx2fg" 
•I0728 23:39:16.604517   10495 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-c54nn" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0728 23:39:16.728782   10495 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-c54nn" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0728 23:39:16.733425   10495 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-c54nn" "namespace"="default"
E0728 23:39:17.753742   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
•E0728 23:39:18.768623   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-56hgx/test-cluster-vq6c2"
E0728 23:39:18.784062   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-vwzzr\" not found" "controller"="cluster" "name"="test3-vwzzr" "namespace"="default"
E0728 23:39:19.784888   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
E0728 23:39:20.811266   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
E0728 23:39:20.811511   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jrxrm/test-cluster-mn6m5"
•E0728 23:39:21.823311   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kx2fg/test-cluster-thjjt"
E0728 23:39:21.827424   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kfrz5: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kfrz5" "namespace"="default"
E0728 23:39:22.828269   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
E0728 23:39:23.841698   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kfrz5: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kfrz5" "namespace"="default"
•E0728 23:39:24.842595   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
E0728 23:39:25.313937   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-wtpsd\" for machine \"test-mhc-machine-xgc7m\" in namespace \"test-mhc-f9ptt\": Cluster.cluster.x-k8s.io \"test-cluster-wtpsd\" not found" "controller"="machine" "name"="test-mhc-machine-xgc7m" "namespace"="test-mhc-f9ptt"
E0728 23:39:25.843605   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kfrz5: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kfrz5" "namespace"="default"
E0728 23:39:26.857369   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
I0728 23:39:26.906104   10495 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-nhvrt" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0728 23:39:26.931199   10495 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-nhvrt" "namespace"="default" 
E0728 23:39:26.955828   10495 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-nhvrt" "namespace"="default"
E0728 23:39:27.858177   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kfrz5: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kfrz5" "namespace"="default"
I0728 23:39:27.978253   10495 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-nhvrt" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0728 23:39:27.978470   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-nhvrt" "namespace"="default" "noderef"="id-node-1"
E0728 23:39:27.990291   10495 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-nhvrt" "namespace"="default"
E0728 23:39:28.862732   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
•I0728 23:39:28.939137   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-ttjfq" "namespace"="ms-test" "creating"=2 "need"=2
I0728 23:39:28.939174   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-ttjfq" "namespace"="ms-test" 
I0728 23:39:28.952598   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-ttjfq-p4b7b\"" "machineset"="ms-ttjfq" "namespace"="ms-test" 
I0728 23:39:28.952649   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-ttjfq" "namespace"="ms-test" 
I0728 23:39:28.966141   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-ttjfq-ln7lq\"" "machineset"="ms-ttjfq" "namespace"="ms-test" 
I0728 23:39:28.990956   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-pg5wc" "machine"="test6-nhvrt" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"541e818c-6c1a-4ba1-979f-af34ebef0ce1","apiVersion":"v1"}
E0728 23:39:29.011336   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-nhvrt\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-nhvrt" "namespace"="default"
I0728 23:39:29.076568   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-ttjfq" "namespace"="ms-test" "creating"=1 "need"=2
I0728 23:39:29.076615   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-ttjfq" "namespace"="ms-test" 
I0728 23:39:29.091427   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-ttjfq-dxj8k\"" "machineset"="ms-ttjfq" "namespace"="ms-test" 
E0728 23:39:29.313333   10495 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-ttjfq-dxj8k-kqtpj for machine ms-test/ms-ttjfq-dxj8k: the cache is not started, can not read objects" "machineset"="ms-ttjfq" "namespace"="ms-test" 
E0728 23:39:29.451596   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0728 23:39:29.506754   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0728 23:39:29.506794   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" 
I0728 23:39:29.517707   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-r28n2-6657c7fddb-7cdn9\"" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" 
I0728 23:39:29.517767   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" 
I0728 23:39:29.527599   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-r28n2-6657c7fddb-hzt8f\"" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" 
I0728 23:39:29.597107   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
... skipping 4 lines ...
I0728 23:39:29.704893   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0728 23:39:29.704947   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" 
I0728 23:39:29.720364   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-r28n2-6657c7fddb-8lvn8\"" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" 
I0728 23:39:29.813615   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0728 23:39:29.813654   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" 
I0728 23:39:29.823225   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-r28n2-cdfc6fd6c-md5d7\"" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" 
E0728 23:39:29.863460   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kfrz5: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kfrz5" "namespace"="default"
E0728 23:39:30.011885   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-ttjfq-ln7lq\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-ttjfq-ln7lq" "namespace"="ms-test"
E0728 23:39:30.033606   10495 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-r28n2-cdfc6fd6c-md5d7-bb56d for machine md-test/md-r28n2-cdfc6fd6c-md5d7: the cache is not started, can not read objects" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" 
I0728 23:39:30.079245   10495 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0728 23:39:30.079323   10495 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0728 23:39:30.083147   10495 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-r28n2-6657c7fddb" "namespace"="md-test" "machine"="md-r28n2-6657c7fddb-vwtsh"
I0728 23:39:30.191401   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0728 23:39:30.191445   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" 
I0728 23:39:30.199444   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-r28n2-cdfc6fd6c-qsfct\"" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" 
... skipping 14 lines ...
I0728 23:39:30.786206   10495 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" "machine"="md-r28n2-cdfc6fd6c-qsfct"
I0728 23:39:30.807463   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-r28n2-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0728 23:39:30.807505   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-r28n2-74d45c49c5" "namespace"="md-test" 
I0728 23:39:30.819433   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-r28n2-74d45c49c5-gzhld\"" "machineset"="md-r28n2-74d45c49c5" "namespace"="md-test" 
I0728 23:39:30.863916   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-pg5wc" "namespace"="default" "count"=1
I0728 23:39:30.863974   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-pg5wc" "namespace"="default" "descendants"="Control plane machines: test6-nhvrt" "indirect descendants count"=0
E0728 23:39:30.878991   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-c54nn: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-c54nn" "namespace"="default"
I0728 23:39:31.009910   10495 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0728 23:39:31.009963   10495 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0728 23:39:31.012582   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-pg5wc" "machine"="test6-nhvrt" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"541e818c-6c1a-4ba1-979f-af34ebef0ce1","apiVersion":"v1"}
E0728 23:39:31.013611   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-nhvrt\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-nhvrt" "namespace"="default"
I0728 23:39:31.041663   10495 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" "machine"="md-r28n2-cdfc6fd6c-z5w6d"
I0728 23:39:31.081869   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-r28n2-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0728 23:39:31.081920   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-r28n2-74d45c49c5" "namespace"="md-test" 
I0728 23:39:31.089991   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-r28n2-74d45c49c5-2p65n\"" "machineset"="md-r28n2-74d45c49c5" "namespace"="md-test" 
•

Ran 16 of 16 Specs in 15.878 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.88s)
PASS
Tearing down test suite
E0728 23:39:31.158332   10495 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0728 23:39:31.158405   10495 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-349300194/tls.crt: no such file or directory"  
I0728 23:39:31.158462   10495 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0728 23:39:31.158498   10495 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0728 23:39:31.158519   10495 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0728 23:39:31.158543   10495 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0728 23:39:31.158466   10495 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0728 23:39:31.158567   10495 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0728 23:39:31.158553   10495 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
E0728 23:39:31.158906   10495 event.go:272] Unable to write event: 'Patch http://127.0.0.1:45473/api/v1/namespaces/md-test/events/md-r28n2.169618c9f7775699: read tcp 127.0.0.1:33780->127.0.0.1:45473: read: connection reset by peer' (may retry after sleeping)
E0728 23:39:31.159383   10495 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to retrieve InfrastructureMachineTemplate external object \"md-test\"/\"md-template\": Get http://127.0.0.1:45473/apis/infrastructure.cluster.x-k8s.io/v1alpha3/namespaces/md-test/infrastructuremachinetemplates/md-template: dial tcp 127.0.0.1:45473: connect: connection refused" "machineset"="md-r28n2-cdfc6fd6c" "namespace"="md-test" 
E0728 23:39:31.159731   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to retrieve InfrastructureMachineTemplate external object \"md-test\"/\"md-template\": Get http://127.0.0.1:45473/apis/infrastructure.cluster.x-k8s.io/v1alpha3/namespaces/md-test/infrastructuremachinetemplates/md-template: dial tcp 127.0.0.1:45473: connect: connection refused" "controller"="machineset" "name"="md-r28n2-cdfc6fd6c" "namespace"="md-test"
E0728 23:39:31.160399   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-r28n2\" not found" "controller"="machinedeployment" "name"="md-r28n2" "namespace"="md-test"
E0728 23:39:31.195257   10495 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:45473/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1248&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:45473: connect: connection refused
E0728 23:39:31.195362   10495 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:45473/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1248&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:45473: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	64.278s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0728 23:38:41.877949   11016 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0728 23:38:41.877971   11016 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0728 23:38:41.878137   11016 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0728 23:38:41.879029   11016 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0728 23:38:41.879202   11016 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=46313
I0728 23:38:41.879303   11016 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0728 23:38:43.998652   11016 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-h2rml/test-cluster"
•E0728 23:38:44.441094   11016 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-5wtks/test-cluster"
•E0728 23:38:44.998080   11016 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:37387/?timeout=50ms: dial tcp 127.0.0.1:37387: connect: connection refused"  "cluster"="cluster-cache-test-9vg5l/test-cluster"
•I0728 23:38:45.288964   11016 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":{}}}
I0728 23:38:45.489335   11016 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0728 23:38:45.489417   11016 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0728 23:38:45.489513   11016 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0728 23:38:46.035938   11016 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0728 23:38:46.051812   11016 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0728 23:38:46.152488   11016 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0728 23:38:46.152549   11016 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•E0728 23:38:46.319860   11016 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
I0728 23:38:46.319884   11016 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0728 23:38:46.319927   11016 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-234794707/tls.crt: no such file or directory"  
I0728 23:38:46.319952   11016 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0728 23:38:46.386295   11016 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:42107/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:42107: connect: connection refused


Ran 5 of 5 Specs in 16.788 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.79s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.978s
?   	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
I0728 23:38:53.425338   11620 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
E0728 23:38:53.426573   11620 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
I0728 23:38:53.427185   11620 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0728 23:38:53.427317   11620 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
I0728 23:39:12.955994   11620 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
I0728 23:39:12.956220   11620 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: 1627515519
Will run 1 of 1 specs

E0728 23:39:12.977217   11620 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-5vnbj4\" not found" "kubeadmControlPlane"="kcp-foo-5vnbj4" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.017 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0728 23:39:12.978708   11620 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-uxaup3" "kubeadmControlPlane"="kcp-foo-uxaup3" "namespace"="test" 
I0728 23:39:14.754060   11620 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-uxaup3" "kubeadmControlPlane"="kcp-foo-uxaup3" "namespace"="test" "needRollout"=["kcp-foo-uxaup3-dftrr"]
I0728 23:39:14.754194   11620 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-uxaup3" "kubeadmControlPlane"="kcp-foo-uxaup3" "namespace"="test" "failures"="[machine kcp-foo-uxaup3-bhrx9 does not have APIServerPodHealthy condition, machine kcp-foo-uxaup3-bhrx9 does not have ControllerManagerPodHealthy condition, machine kcp-foo-uxaup3-bhrx9 does not have SchedulerPodHealthy condition, machine kcp-foo-uxaup3-bhrx9 does not have EtcdPodHealthy condition, machine kcp-foo-uxaup3-bhrx9 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.78s)
... skipping 60 lines ...
==================================
Random Seed: 1627515518
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: 1627515518
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
E0728 23:38:54.874851   11596 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"  
E0728 23:39:03.197990   11596 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"  
E0728 23:39:12.184012   11596 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"  
E0728 23:39:23.314307   11596 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"  
E0728 23:39:39.787499   11596 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"  
E0728 23:39:52.796123   11596 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"  
E0728 23:40:10.443559   11596 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"  
E0728 23:40:31.366942   11596 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"  
E0728 23:41:02.383451   11596 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"  
E0728 23:41:47.540633   11596 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 ...
I0728 23:39:02.000547   11905 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0728 23:39:02.097982   11905 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0728 23:39:02.101071   11905 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0728 23:39:02.198450   11905 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0728 23:39:02.198535   11905 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0728 23:39:02.273643   11905 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-l79b9h"} 
•E0728 23:39:02.299772   11905 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"
I0728 23:39:03.349976   11905 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-208jwr"} 
E0728 23:39:03.382387   11905 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"
•E0728 23:39:04.444138   11905 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"
E0728 23:39:05.469701   11905 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"
•E0728 23:39:06.633379   11905 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"
•E0728 23:39:07.665082   11905 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"
E0728 23:39:08.689986   11905 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"
•I0728 23:39:08.691193   11905 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0728 23:39:08.691367   11905 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0728 23:39:08.691378   11905 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 


Ran 5 of 5 Specs in 20.969 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.97s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	21.082s
?   	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
E0728 23:38:53.664151   12095 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.01s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 91 lines ...
•I0728 23:39:08.419332   12095 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0728 23:39:08.449569   12095 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0728 23:39:08.493866   12095 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0728 23:39:08.496046   12095 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0728 23:39:08.514857   12095 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0728 23:39:08.568399   12095 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0728 23:39:08.571084   12095 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0728 23:39:08.571139   12095 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-363776171/tls.crt: no such file or directory"  
E0728 23:39:08.571161   12095 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0728 23:39:08.571179   12095 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-363776171/tls.crt: no such file or directory"  
I0728 23:39:08.571349   12095 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0728 23:39:08.617755   12095 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


Ran 9 of 9 Specs in 14.829 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.83s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	15.198s
?   	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
•I0728 23:39:34.503069   15127 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0728 23:39:34.503605   15127 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0728 23:39:34.503654   15127 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-309433523/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.030 seconds
FAIL! -- 13 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestPatch (8.03s)
=== 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.075s
?   	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.009s
... skipping 88 lines ...
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#01 (0.00s)
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#02 (0.00s)
=== RUN   TestFromUnstructured
--- PASS: TestFromUnstructured (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/yaml	0.037s
FAIL
make: *** [Makefile:116: test] Error 1
+ EXIT_VALUE=2
+ set +o xtrace