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-29 13:30
Elapsed4m15s
Revision95f8b2c714453523087f0d5edd204cee43518ad2
Refs 5013

No Test Failures!


Error lines from build-log.txt

... skipping 781 lines ...
I0729 13:31:44.531231    8441 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0729 13:31:45.211644    8441 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" 
•I0729 13:31:45.220917    8441 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 11.717 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.72s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	39.642s
=== 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 ...
I0729 13:31:31.936165   10532 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0729 13:31:31.936463   10532 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0729 13:31:31.936700   10532 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}},"status":{"bootstrapReady":false,"infrastructureReady":false}}}
I0729 13:31:31.936754   10532 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0729 13:31:31.936780   10532 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0729 13:31:31.936802   10532 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2021/07/29 13:31:32 http: TLS handshake error from 127.0.0.1:39702: 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
I0729 13:31:32.335269   10532 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"
I0729 13:31:32.338090   10532 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
I0729 13:31:32.380788   10532 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
I0729 13:31:32.382245   10532 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"
E0729 13:31:32.382532   10532 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
I0729 13:31:32.382870   10532 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.02s)
    --- 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.02s)
=== RUN   TestWatches
I0729 13:31:32.679240   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0729 13:31:32.779770   10532 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0729 13:31:32.789057   10532 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-5dkcx" "namespace"="test-machine-watches-rckhc" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0729 13:31:32.789159   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0729 13:31:32.898788   10532 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-5dkcx" "namespace"="test-machine-watches-rckhc" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0729 13:31:32.898880   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0729 13:31:32.999336   10532 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-5dkcx" "namespace"="test-machine-watches-rckhc" "noderef"="node-1"
E0729 13:31:33.019308   10532 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0729 13:31:33.019372   10532 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0729 13:31:33.053850   10532 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-5dkcx" "namespace"="test-machine-watches-rckhc" "noderef"="node-1"
E0729 13:31:33.067782   10532 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-5dkcx\" in namespace \"test-machine-watches-rckhc\", requeuing: requeue in 1s"  
E0729 13:31:33.080664   10532 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-5dkcx\" in namespace \"test-machine-watches-rckhc\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-5dkcx\" in namespace \"test-machine-watches-rckhc\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-5dkcx" "namespace"="test-machine-watches-rckhc"
--- PASS: TestWatches (0.71s)
=== 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
I0729 13:31:33.199987   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-xzjr7" "namespace"="test-machine-watches-rckhc" "count"=1
I0729 13:31:33.200058   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-xzjr7" "namespace"="test-machine-watches-rckhc" "descendants"="Worker machines: machine-created-5dkcx" "indirect descendants count"=0
I0729 13:31:33.219398   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-xzjr7" "namespace"="test-machine-watches-rckhc" "count"=1
I0729 13:31:33.219833   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-xzjr7" "namespace"="test-machine-watches-rckhc" "descendants"="Worker machines: machine-created-5dkcx" "indirect descendants count"=0
I0729 13:31:34.081226   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xzjr7" "machine"="machine-created-5dkcx" "namespace"="test-machine-watches-rckhc" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"ccd47325-ed0f-4828-bd24-2e936657c2ee","apiVersion":"v1"}
E0729 13:31:34.123417   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-5dkcx\" not found" "controller"="machine" "name"="machine-created-5dkcx" "namespace"="test-machine-watches-rckhc"
E0729 13:31:35.186885   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-mk26d\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-bn9n8\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-bn9n8: secrets \"machine-reconcile-bn9n8-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-mk26d" "namespace"="default"
I0729 13:31:36.187475   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-bn9n8" "machine"="machine-created-mk26d" "namespace"="default" "cause"="noderef is nil" "node"=null
I0729 13:31:36.223036   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-bn9n8" "machine"="machine-created-mk26d" "namespace"="default" "cause"="noderef is nil" "node"=null
I0729 13:31:36.253466   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-bn9n8" "machine"="machine-created-mk26d" "namespace"="default" "cause"="noderef is nil" "node"=null
E0729 13:31:36.299429   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-mk26d\" not found" "controller"="machine" "name"="machine-created-mk26d" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.22s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.22s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
    --- PASS: TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one (0.00s)
    --- PASS: TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer (0.00s)
=== RUN   TestMachineOwnerReference
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0729 13:31:36.324890   10532 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"
I0729 13:31:36.325086   10532 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
E0729 13:31:36.333239   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-bn9n8\" not found" "controller"="cluster" "name"="machine-reconcile-bn9n8" "namespace"="default"
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0729 13:31:36.351901   10532 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"
I0729 13:31:36.352098   10532 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
I0729 13:31:36.355426   10532 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"
I0729 13:31:36.355505   10532 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
... skipping 125 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0729 13:31:36.498052   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jfrmk" "namespace"="test-mhc-rdjx4" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0729 13:31:36.531526   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0729 13:31:36.531860   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-vpwj7\" not found"  "cluster"="test-mhc-rdjx4/test-cluster-vpwj7"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E0729 13:31:36.637924   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-jfrmk\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-jfrmk\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-jfrmk" "namespace"="test-mhc-rdjx4"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
error cannot retrieve mhc in ctx: MachineHealthCheck.cluster.x-k8s.io "test-mhc-wp2jl" not foundI0729 13:31:37.638262   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rg2zs" "namespace"="test-mhc-2n5zl" 
I0729 13:31:37.638397   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jfrmk" "namespace"="test-mhc-rdjx4" 
I0729 13:31:37.638423   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6rj9" "namespace"="test-mhc-rvqgn" 
I0729 13:31:37.638445   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wp2jl" "namespace"="test-mhc-xxcqj" 
I0729 13:31:37.673009   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 13:31:37.705708   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wp2jl" "namespace"="test-mhc-xxcqj" 
I0729 13:31:37.745270   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wp2jl" "namespace"="test-mhc-xxcqj" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0729 13:31:37.752262   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xxcqj/test-cluster-k98cq"
E0729 13:31:37.754435   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-k98cq\" not found" "controller"="cluster" "name"="test-cluster-k98cq" "namespace"="test-mhc-xxcqj"
I0729 13:31:37.771099   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wgb2r" "namespace"="test-mhc-kkxnh" 
I0729 13:31:37.789154   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 13:31:37.915216   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wgb2r" "namespace"="test-mhc-kkxnh" 
I0729 13:31:37.920968   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wgb2r" "namespace"="test-mhc-kkxnh" 
E0729 13:31:37.981939   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kkxnh/test-cluster-pdrjx"
I0729 13:31:38.008389   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wgb2r" "namespace"="test-mhc-kkxnh" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0729 13:31:38.145184   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
inframachine created: test-mhc-machine-infra-2zm2k
I0729 13:31:38.163422   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-bbm5n
I0729 13:31:38.208975   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.209321   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
I0729 13:31:38.230027   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.230389   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
I0729 13:31:38.231962   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.232311   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
I0729 13:31:38.238481   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.238840   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
I0729 13:31:38.251683   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.252008   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
I0729 13:31:38.256067   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.256364   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
E0729 13:31:38.269993   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-59mz5, got []"  "node"="test-mhc-node-59mz5"
I0729 13:31:38.270085   10532 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-bbm5n" "namespace"="test-mhc-l8s5x" "noderef"="test-mhc-node-59mz5"
node created: test-mhc-node-59mz5
E0729 13:31:38.270693   10532 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-59mz5"
E0729 13:31:38.275644   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-59mz5, got []"  "node"="test-mhc-node-59mz5"
E0729 13:31:38.275696   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-59mz5, got []"  "node"="test-mhc-node-59mz5"
E0729 13:31:38.276532   10532 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-59mz5"
E0729 13:31:38.276573   10532 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-59mz5"
I0729 13:31:38.277978   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
inframachine created: test-mhc-machine-infra-bsszc
machine created: test-mhc-machine-6mwbg
I0729 13:31:38.297349   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.311449   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.312848   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
... skipping 68 lines ...
I0729 13:31:38.484291   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.486294   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.487308   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.488496   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.489441   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.490236   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.490511   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-6mwbg/"
node created: test-mhc-node-krffh
E0729 13:31:38.504693   10532 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-krffh"
E0729 13:31:38.504879   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-krffh, got []"  "node"="test-mhc-node-krffh"
I0729 13:31:38.505184   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.505578   10532 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-l8s5x/test-mhc-m4zvd/test-mhc-machine-6mwbg/"
I0729 13:31:38.514797   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.534397   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
Cleaning up nodes, machines and infra machines.
I0729 13:31:38.535529   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.540442   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.540871   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
I0729 13:31:38.564195   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-s9z4t" "machine"="test-mhc-machine-bbm5n" "namespace"="test-mhc-l8s5x" "cause"="no control plane members" "node"={"kind":"Node","name":"test-mhc-node-59mz5","uid":"665ef32b-f1aa-4a35-af7c-016bbd18c797","apiVersion":"v1"}
I0729 13:31:38.578691   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
I0729 13:31:38.579217   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-l8s5x/test-mhc-m4zvd/test-mhc-machine-bbm5n/"
I0729 13:31:38.579563   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-l8s5x/test-mhc-m4zvd/test-mhc-machine-6mwbg/"
E0729 13:31:38.604869   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-l8s5x/test-cluster-s9z4t"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
I0729 13:31:38.609837   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4zvd" "namespace"="test-mhc-l8s5x" 
E0729 13:31:38.626766   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-bbm5n\" not found" "controller"="machine" "name"="test-mhc-machine-bbm5n" "namespace"="test-mhc-l8s5x"
I0729 13:31:38.641378   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
inframachine created: test-mhc-machine-infra-bb9c7
I0729 13:31:38.668629   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-jdznv
I0729 13:31:38.690166   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.691271   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
... skipping 32 lines ...
I0729 13:31:38.761619   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.763643   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.767003   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.771263   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.773634   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.776778   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
E0729 13:31:38.776959   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-rckhc/machine-reconcile-xzjr7"
I0729 13:31:38.779281   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.781292   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.782979   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.784701   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.786661   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:38.792009   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
... skipping 409 lines ...
I0729 13:31:39.608409   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.615819   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.617810   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.619463   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.621248   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.626560   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
E0729 13:31:39.630769   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:39.631265   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.633169   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.634878   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.637044   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.639140   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:39.640791   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
... skipping 453 lines ...
I0729 13:31:40.629712   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:40.632159   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:40.633910   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:40.640929   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:40.652368   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:40.656679   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
E0729 13:31:40.657648   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:40.658073   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:40.658374   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-jdznv/"
I0729 13:31:40.675861   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:40.676173   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-jdznv/"
E0729 13:31:40.682379   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ng75n, got []"  "node"="test-mhc-node-ng75n"
node created: test-mhc-node-ng75n
I0729 13:31:40.690861   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
inframachine created: test-mhc-machine-infra-qt7hh
I0729 13:31:40.703880   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
machine created: test-mhc-machine-fjkr4
I0729 13:31:40.711663   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
... skipping 344 lines ...
I0729 13:31:41.690791   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.693874   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.696257   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.699391   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.702270   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.704392   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
E0729 13:31:41.708708   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:41.708273   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.710062   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.716244   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.719613   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.724417   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:41.726096   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
... skipping 313 lines ...
I0729 13:31:42.713978   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.716043   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.717654   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.719840   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.720799   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.722845   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.723195   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-fjkr4/"
node created: test-mhc-node-b9rch
E0729 13:31:42.739617   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-b9rch, got []"  "node"="test-mhc-node-b9rch"
I0729 13:31:42.740474   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
E0729 13:31:42.741082   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:42.741382   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-fjkr4/"
I0729 13:31:42.742527   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.742963   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-fjkr4/"
I0729 13:31:42.749497   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
inframachine created: test-mhc-machine-infra-2m6q9
I0729 13:31:42.767264   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
machine created: test-mhc-machine-cfgmq
I0729 13:31:42.772526   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:42.778791   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
... skipping 273 lines ...
I0729 13:31:43.789250   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.794640   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.796294   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.802279   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.817750   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.830101   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
E0729 13:31:43.830975   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:43.843135   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-cfgmq/"
I0729 13:31:43.854660   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.855446   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-cfgmq/"
E0729 13:31:43.891731   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nnlwr, got []"  "node"="test-mhc-node-nnlwr"
node created: test-mhc-node-nnlwr
I0729 13:31:43.900946   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.901409   10532 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-g9w8p/test-mhc-97csh/test-mhc-machine-cfgmq/test-mhc-node-nnlwr"
Cleaning up nodes, machines and infra machines.
I0729 13:31:43.920247   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-97csh" "namespace"="test-mhc-g9w8p" 
I0729 13:31:43.920682   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-g9w8p/test-mhc-97csh/test-mhc-machine-cfgmq/"
Cleaning up nodes, machines and infra machines.
I0729 13:31:43.974513   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-l4njb" "namespace"="test-mhc-g9w8p" "count"=2
I0729 13:31:43.974595   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-l4njb" "namespace"="test-mhc-g9w8p" "descendants"="Worker machines: test-mhc-machine-jdznv,test-mhc-machine-fjkr4,test-mhc-machine-cfgmq" "indirect descendants count"=1
I0729 13:31:43.978493   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-l4njb" "namespace"="test-mhc-g9w8p" "count"=2
I0729 13:31:43.978578   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-l4njb" "namespace"="test-mhc-g9w8p" "descendants"="Worker machines: test-mhc-machine-jdznv,test-mhc-machine-fjkr4,test-mhc-machine-cfgmq" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
... skipping 6 lines ...
I0729 13:31:44.302557   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:44.312730   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:44.355424   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:44.436350   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:44.597257   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:44.842936   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-l4njb" "machine"="test-mhc-machine-fjkr4" "namespace"="test-mhc-g9w8p" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-b9rch"}
E0729 13:31:44.893969   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fjkr4\" not found" "controller"="machine" "name"="test-mhc-machine-fjkr4" "namespace"="test-mhc-g9w8p"
I0729 13:31:44.918194   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:45.559147   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:45.894546   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-l4njb" "machine"="test-mhc-machine-cfgmq" "namespace"="test-mhc-g9w8p" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nnlwr"}
E0729 13:31:45.934607   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cfgmq\" not found" "controller"="machine" "name"="test-mhc-machine-cfgmq" "namespace"="test-mhc-g9w8p"
I0729 13:31:46.840105   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
E0729 13:31:46.935026   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:47.935566   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-l4njb" "machine"="test-mhc-machine-jdznv" "namespace"="test-mhc-g9w8p" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ng75n"}
E0729 13:31:47.975670   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jdznv\" not found" "controller"="machine" "name"="test-mhc-machine-jdznv" "namespace"="test-mhc-g9w8p"
I0729 13:31:48.986796   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:48.992036   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
E0729 13:31:48.994513   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
E0729 13:31:48.994606   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-g9w8p/test-cluster-l4njb"
I0729 13:31:49.014779   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
node created: test-mhc-node-8zrgt
E0729 13:31:49.056176   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8zrgt, got []"  "node"="test-mhc-node-8zrgt"
I0729 13:31:49.063754   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
inframachine created: test-mhc-machine-infra-hgpqh
machine created: test-mhc-machine-splhf
I0729 13:31:49.104029   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:49.117561   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:49.118740   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
... skipping 5 lines ...
I0729 13:31:50.016026   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:50.030323   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:50.043113   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:50.054680   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:50.065963   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:50.072414   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
E0729 13:31:50.073244   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:50.098623   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
node created: test-mhc-node-7nm6h
E0729 13:31:50.117416   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7nm6h, got []"  "node"="test-mhc-node-7nm6h"
I0729 13:31:50.142539   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
inframachine created: test-mhc-machine-infra-584bw
I0729 13:31:50.152837   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:50.164943   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
machine created: test-mhc-machine-jpvpc
I0729 13:31:50.178970   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:50.369152   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.084302   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.101736   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.120793   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.142973   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.152926   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.164126   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
E0729 13:31:51.172408   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:51.172699   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.193490   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
node created: test-mhc-node-8tcw2
E0729 13:31:51.274141   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8tcw2, got []"  "node"="test-mhc-node-8tcw2"
Cleaning up nodes, machines and infra machines.
I0729 13:31:51.281489   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.293574   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
Cleaning up nodes, machines and infra machines.
I0729 13:31:51.350021   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-dtq94" "namespace"="test-mhc-6zjn4" "count"=2
I0729 13:31:51.350092   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dtq94" "namespace"="test-mhc-6zjn4" "descendants"="Worker machines: test-mhc-machine-splhf,test-mhc-machine-jpvpc,test-mhc-machine-nbxbk" "indirect descendants count"=1
... skipping 5 lines ...
I0729 13:31:51.490097   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:51.518634   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 13:31:51.536432   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kffzf" "namespace"="test-mhc-6zjn4" 
I0729 13:31:51.536513   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:51.537374   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:52.172975   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dtq94" "machine"="test-mhc-machine-nbxbk" "namespace"="test-mhc-6zjn4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8zrgt"}
E0729 13:31:52.218159   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nbxbk\" not found" "controller"="machine" "name"="test-mhc-machine-nbxbk" "namespace"="test-mhc-6zjn4"
I0729 13:31:53.218811   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dtq94" "machine"="test-mhc-machine-splhf" "namespace"="test-mhc-6zjn4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-7nm6h"}
E0729 13:31:53.271460   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-splhf\" not found" "controller"="machine" "name"="test-mhc-machine-splhf" "namespace"="test-mhc-6zjn4"
I0729 13:31:54.272167   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dtq94" "machine"="test-mhc-machine-jpvpc" "namespace"="test-mhc-6zjn4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8tcw2"}
E0729 13:31:54.321910   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jpvpc\" not found" "controller"="machine" "name"="test-mhc-machine-jpvpc" "namespace"="test-mhc-6zjn4"
I0729 13:31:55.330847   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:55.331558   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
E0729 13:31:55.336387   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:55.336918   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
node created: test-mhc-node-l45cj
E0729 13:31:55.428700   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-l45cj, got []"  "node"="test-mhc-node-l45cj"
E0729 13:31:55.428894   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-l45cj, got []"  "node"="test-mhc-node-l45cj"
I0729 13:31:55.435994   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
inframachine created: test-mhc-machine-infra-p824n
I0729 13:31:55.452346   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:55.453332   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:55.454512   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
machine created: test-mhc-machine-smpff
I0729 13:31:55.460570   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.349963   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.351097   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.358724   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.378646   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.383769   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
E0729 13:31:56.386172   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6zjn4/test-cluster-dtq94"
I0729 13:31:56.394811   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.403684   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.417612   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.435385   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.445108   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.451458   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
E0729 13:31:56.469501   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tc8sw, got []"  "node"="test-mhc-node-tc8sw"
node created: test-mhc-node-tc8sw
I0729 13:31:56.473535   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.480766   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
inframachine created: test-mhc-machine-infra-z9mww
I0729 13:31:56.492759   10532 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-smpff" "namespace"="test-mhc-cwvvz" "noderef"="test-mhc-node-tc8sw"
machine created: test-mhc-machine-d958v
... skipping 4 lines ...
I0729 13:31:56.557043   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
Cleaning up nodes, machines and infra machines.
I0729 13:31:56.611882   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.622044   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
Cleaning up nodes, machines and infra machines.
I0729 13:31:56.633423   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.633943   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cwvvz/test-mhc-x4f8b/test-mhc-machine-mr9bt/"
I0729 13:31:56.675499   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.676057   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cwvvz/test-mhc-x4f8b/test-mhc-machine-mr9bt/"
I0729 13:31:56.676422   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cwvvz/test-mhc-x4f8b/test-mhc-machine-smpff/"
I0729 13:31:56.685179   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fhjwc" "machine"="test-mhc-machine-mr9bt" "namespace"="test-mhc-cwvvz" "cause"="no control plane members" "node"={"name":"test-mhc-node-l45cj"}
I0729 13:31:56.721284   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fhjwc" "namespace"="test-mhc-cwvvz" "count"=3
I0729 13:31:56.721363   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fhjwc" "namespace"="test-mhc-cwvvz" "descendants"="Worker machines: test-mhc-machine-mr9bt,test-mhc-machine-smpff,test-mhc-machine-d958v" "indirect descendants count"=0
I0729 13:31:56.722275   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.722797   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cwvvz/test-mhc-x4f8b/test-mhc-machine-mr9bt/"
I0729 13:31:56.723157   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cwvvz/test-mhc-x4f8b/test-mhc-machine-smpff/"
I0729 13:31:56.726197   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fhjwc" "namespace"="test-mhc-cwvvz" "count"=3
I0729 13:31:56.726246   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fhjwc" "namespace"="test-mhc-cwvvz" "descendants"="Worker machines: test-mhc-machine-smpff,test-mhc-machine-d958v,test-mhc-machine-mr9bt" "indirect descendants count"=0
I0729 13:31:56.733639   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
I0729 13:31:56.734117   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cwvvz/test-mhc-x4f8b/test-mhc-machine-mr9bt/"
I0729 13:31:56.734504   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cwvvz/test-mhc-x4f8b/test-mhc-machine-smpff/"
=== 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
I0729 13:31:56.741635   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x4f8b" "namespace"="test-mhc-cwvvz" 
E0729 13:31:56.767422   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mr9bt\" not found" "controller"="machine" "name"="test-mhc-machine-mr9bt" "namespace"="test-mhc-cwvvz"
I0729 13:31:56.862770   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
inframachine created: test-mhc-machine-infra-46sf5
I0729 13:31:56.879986   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-kqk8g
I0729 13:31:57.005732   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.006853   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
... skipping 384 lines ...
I0729 13:31:57.807489   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.809290   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.811711   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.813475   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.815091   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.816747   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
E0729 13:31:57.817633   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-smpff\" not found" "controller"="machine" "name"="test-mhc-machine-smpff" "namespace"="test-mhc-cwvvz"
I0729 13:31:57.818429   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.820821   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.822800   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.824781   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.826943   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:57.828715   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
... skipping 490 lines ...
I0729 13:31:58.868102   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.870161   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.872244   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.874471   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.876530   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.881997   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
E0729 13:31:58.885747   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-d958v\" not found" "controller"="machine" "name"="test-mhc-machine-d958v" "namespace"="test-mhc-cwvvz"
I0729 13:31:58.886715   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.888674   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.890593   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.892895   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.894635   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:58.896245   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
... skipping 472 lines ...
I0729 13:31:59.895059   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.895764   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.896763   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.898873   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.900932   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.902828   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
E0729 13:31:59.902900   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:31:59.903106   10532 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-4kmx7/test-mhc-s6gql/test-mhc-machine-kqk8g/"
I0729 13:31:59.911756   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.912053   10532 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-4kmx7/test-mhc-s6gql/test-mhc-machine-kqk8g/"
I0729 13:31:59.912862   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.913094   10532 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-4kmx7/test-mhc-s6gql/test-mhc-machine-kqk8g/"
E0729 13:31:59.920394   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5c2bj, got []"  "node"="test-mhc-node-5c2bj"
E0729 13:31:59.920526   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5c2bj, got []"  "node"="test-mhc-node-5c2bj"
node created: test-mhc-node-5c2bj
I0729 13:31:59.931523   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.946582   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.957178   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.957494   10532 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-4kmx7/test-mhc-s6gql/test-mhc-machine-kqk8g/test-mhc-node-5c2bj"
I0729 13:31:59.975617   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.975935   10532 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-4kmx7/test-mhc-s6gql/test-mhc-machine-kqk8g/test-mhc-node-5c2bj"
Cleaning up nodes, machines and infra machines.
I0729 13:31:59.985077   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:31:59.985424   10532 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4kmx7/test-mhc-s6gql/test-mhc-machine-kqk8g/"
I0729 13:32:00.000252   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qj96w" "namespace"="test-mhc-4kmx7" "descendants"="Worker machines: test-mhc-machine-kqk8g" "indirect descendants count"=1
I0729 13:32:00.004980   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qj96w" "namespace"="test-mhc-4kmx7" "descendants"="Worker machines: test-mhc-machine-kqk8g" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0729 13:32:00.098417   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" "creating"=1 "need"=1
I0729 13:32:00.098480   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" 
I0729 13:32:00.116109   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-zwkpn-wfjbk\"" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" 
I0729 13:32:00.147507   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s6gql" "namespace"="test-mhc-4kmx7" 
I0729 13:32:00.196186   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:00.210731   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 13:32:00.329353   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:00.337169   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:00.903532   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qj96w" "machine"="test-mhc-machine-kqk8g" "namespace"="test-mhc-4kmx7" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5c2bj"}
E0729 13:32:00.943578   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kqk8g\" not found" "controller"="machine" "name"="test-mhc-machine-kqk8g" "namespace"="test-mhc-4kmx7"
I0729 13:32:01.329584   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
E0729 13:32:01.741017   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-cwvvz/test-cluster-fhjwc"
I0729 13:32:01.953037   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:01.953705   10532 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" 
I0729 13:32:01.956732   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:01.957416   10532 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" 
I0729 13:32:01.966737   10532 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:01.966786   10532 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
... skipping 3 lines ...
I0729 13:32:01.986305   10532 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" 
I0729 13:32:01.992054   10532 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:01.992188   10532 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.004297   10532 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.004354   10532 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.330568   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.331006   10532 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-gtwnq/test-mhc-s247b/mhc-ms-zwkpn-wfjbk/"
I0729 13:32:02.340072   10532 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.345342   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.345653   10532 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-gtwnq/test-mhc-s247b/mhc-ms-zwkpn-wfjbk/"
I0729 13:32:02.348504   10532 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.348555   10532 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.358041   10532 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.358377   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.359283   10532 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-gtwnq/test-mhc-s247b/mhc-ms-zwkpn-wfjbk/"
I0729 13:32:02.366979   10532 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.367035   10532 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" 
I0729 13:32:02.453293   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7v7nz" "namespace"="test-mhc-gtwnq" "count"=1
I0729 13:32:02.453356   10532 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-7v7nz" "namespace"="test-mhc-gtwnq" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-zwkpn"
I0729 13:32:02.455586   10532 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-zwkpn" "namespace"="test-mhc-gtwnq" "machine"="mhc-ms-zwkpn-wfjbk"
I0729 13:32:02.458989   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s247b" "namespace"="test-mhc-gtwnq" 
... skipping 5 lines ...
I0729 13:32:02.644801   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7v7nz" "machine"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq" "cause"="cluster is being deleted" "node"=null
I0729 13:32:02.648562   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
inframachine created: test-mhc-machine-infra-nftg8
I0729 13:32:02.668339   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-gz825
I0729 13:32:02.691270   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
E0729 13:32:02.702227   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-zwkpn-wfjbk\" not found" "controller"="machine" "name"="mhc-ms-zwkpn-wfjbk" "namespace"="test-mhc-gtwnq"
I0729 13:32:02.702514   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:02.703604   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:02.705389   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:02.707401   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:02.709342   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:02.711358   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
... skipping 474 lines ...
I0729 13:32:03.708899   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:03.710607   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:03.711367   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:03.712756   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:03.714562   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
node created: test-mhc-node-p847g
E0729 13:32:03.781118   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
E0729 13:32:03.781325   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
E0729 13:32:03.781786   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
I0729 13:32:03.785209   10532 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-gz825" "namespace"="test-mhc-mrfps" "noderef"="test-mhc-node-p847g"
E0729 13:32:03.789203   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
E0729 13:32:03.789248   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
E0729 13:32:03.789901   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
E0729 13:32:03.789940   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
E0729 13:32:03.793290   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
E0729 13:32:03.793330   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p847g, got []"  "node"="test-mhc-node-p847g"
I0729 13:32:03.808590   10532 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-gz825" "target"="test-mhc-mrfps/test-mhc-jngfq/test-mhc-machine-gz825/"
I0729 13:32:03.826623   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:03.877927   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:03.891112   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:03.945185   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:04.013873   10532 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-gz825" "target"="test-mhc-mrfps/test-mhc-jngfq/test-mhc-machine-gz825/test-mhc-node-p847g"
I0729 13:32:04.042069   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
Cleaning up nodes, machines and infra machines.
I0729 13:32:04.050144   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:04.053518   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:04.059921   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:04.064200   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:04.071745   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ntrjl" "namespace"="test-mhc-mrfps" "count"=1
I0729 13:32:04.071818   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ntrjl" "namespace"="test-mhc-mrfps" "descendants"="Worker machines: test-mhc-machine-gz825" "indirect descendants count"=0
I0729 13:32:04.075296   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
I0729 13:32:04.077559   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ntrjl" "namespace"="test-mhc-mrfps" "count"=1
I0729 13:32:04.077616   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ntrjl" "namespace"="test-mhc-mrfps" "descendants"="Worker machines: test-mhc-machine-gz825" "indirect descendants count"=0
E0729 13:32:04.079986   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-gz825\" in namespace \"test-mhc-mrfps\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-gz825" "namespace"="test-mhc-mrfps"
I0729 13:32:04.083803   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jngfq" "namespace"="test-mhc-mrfps" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0729 13:32:04.136813   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
inframachine created: test-mhc-machine-infra-5g4hw
I0729 13:32:04.163221   10532 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-qr5kv
... skipping 350 lines ...
I0729 13:32:05.007621   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.010147   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.012167   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.014716   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.016591   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.019578   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
E0729 13:32:05.019998   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4kmx7/test-cluster-qj96w"
I0729 13:32:05.021589   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.023276   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.024818   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.026405   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.029425   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.031219   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
... skipping 46 lines ...
I0729 13:32:05.119049   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.121355   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.123198   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.124922   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.126676   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.128477   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
E0729 13:32:05.129502   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gz825\" not found" "controller"="machine" "name"="test-mhc-machine-gz825" "namespace"="test-mhc-mrfps"
I0729 13:32:05.130271   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.132417   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.134232   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.135984   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.137664   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:05.139588   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
... skipping 454 lines ...
I0729 13:32:06.130798   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.132811   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.134742   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.136821   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.138678   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.139814   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
E0729 13:32:06.141757   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
I0729 13:32:06.142017   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.145756   10532 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-qr5kv" "target"="test-mhc-qzm6r/test-mhc-rmqwm/test-mhc-machine-qr5kv/"
I0729 13:32:06.156951   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
E0729 13:32:06.177658   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4b7tc, got []"  "node"="test-mhc-node-4b7tc"
E0729 13:32:06.177858   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4b7tc, got []"  "node"="test-mhc-node-4b7tc"
E0729 13:32:06.177908   10532 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4b7tc, got []"  "node"="test-mhc-node-4b7tc"
node created: test-mhc-node-4b7tc
I0729 13:32:06.187206   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.237140   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.243957   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.247862   10532 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-qr5kv" "target"="test-mhc-qzm6r/test-mhc-rmqwm/test-mhc-machine-qr5kv/test-mhc-node-4b7tc"
I0729 13:32:06.275488   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.285394   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.310541   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.318273   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
Cleaning up nodes, machines and infra machines.
I0729 13:32:06.325278   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.339283   10532 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-qr5kv" "target"="test-mhc-qzm6r/test-mhc-rmqwm/test-mhc-machine-qr5kv/"
I0729 13:32:06.354916   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-pdtrg" "namespace"="test-mhc-qzm6r" "descendants"="Worker machines: test-mhc-machine-qr5kv" "indirect descendants count"=1
I0729 13:32:06.365860   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-pdtrg" "namespace"="test-mhc-qzm6r" "descendants"="Worker machines: test-mhc-machine-qr5kv" "indirect descendants count"=1
I0729 13:32:06.372931   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
I0729 13:32:06.377535   10532 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rmqwm" "namespace"="test-mhc-qzm6r" 
--- PASS: TestMachineHealthCheck_Reconcile (29.91s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.06s)
... skipping 14 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.63s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.28s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0729 13:32:06.381714   10532 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
E0729 13:32:06.383041   10532 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.01s)
    --- 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
E0729 13:32:06.390287   10532 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0729 13:32:06.391032   10532 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
E0729 13:32:06.391443   10532 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0729 13:32:06.393766   10532 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0729 13:32:06.394259   10532 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0729 13:32:06.395971   10532 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0729 13:32:06.404369   10532 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
E0729 13:32:06.405818   10532 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1627565482
Will run 16 of 16 specs

•E0729 13:32:06.534099   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-2qclg\" not found" "controller"="cluster" "name"="test1-2qclg" "namespace"="default"
I0729 13:32:07.142500   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-pdtrg" "machine"="test-mhc-machine-qr5kv" "namespace"="test-mhc-qzm6r" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4b7tc"}
E0729 13:32:07.192163   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qr5kv\" not found" "controller"="machine" "name"="test-mhc-machine-qr5kv" "namespace"="test-mhc-qzm6r"
E0729 13:32:07.554987   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gtwnq/test-cluster-7v7nz"
•I0729 13:32:07.660375   10532 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-kp6ch" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0729 13:32:07.880720   10532 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-kp6ch" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0729 13:32:07.885758   10532 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-kp6ch" "namespace"="default"
E0729 13:32:08.903151   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
•E0729 13:32:09.919598   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-hdfl4\" not found" "controller"="cluster" "name"="test3-hdfl4" "namespace"="default"
E0729 13:32:10.920466   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
E0729 13:32:11.946580   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mrfps/test-cluster-ntrjl"
E0729 13:32:11.947137   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
•E0729 13:32:12.959833   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qzm6r/test-cluster-pdtrg"
E0729 13:32:12.963858   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:13.964585   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
E0729 13:32:14.975698   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
•E0729 13:32:15.976390   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
E0729 13:32:16.382315   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
E0729 13:32:16.977364   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:17.987608   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
I0729 13:32:18.072614   10532 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dd8m2" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0729 13:32:18.083407   10532 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-dd8m2" "namespace"="default" 
E0729 13:32:18.100527   10532 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-dd8m2" "namespace"="default"
E0729 13:32:18.988415   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
I0729 13:32:19.114750   10532 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dd8m2" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0729 13:32:19.114975   10532 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-dd8m2" "namespace"="default" "noderef"="id-node-1"
E0729 13:32:19.128769   10532 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-dd8m2" "namespace"="default"
E0729 13:32:19.993096   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"

------------------------------
• [SLOW TEST:5.044 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 21 lines ...
I0729 13:32:20.071262   10532 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"
•I0729 13:32:20.072462   10532 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"
I0729 13:32:20.073004   10532 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"
I0729 13:32:20.073491   10532 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0729 13:32:20.073512   10532 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0729 13:32:20.073880   10532 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0729 13:32:20.074975   10532 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" 
•I0729 13:32:20.129203   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-794x2" "machine"="test6-dd8m2" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"3ab048db-e745-473a-b9cb-ef31cfb2862b","apiVersion":"v1"}
I0729 13:32:20.130099   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0729 13:32:20.130147   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.145389   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-snwvh-6657c7fddb-lc8xn\"" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.145547   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
E0729 13:32:20.147895   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dd8m2\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dd8m2" "namespace"="default"
I0729 13:32:20.162181   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-snwvh-6657c7fddb-qqcjr\"" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.225804   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0729 13:32:20.225856   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.241457   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-snwvh-6657c7fddb-kw94n\"" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.241552   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.250910   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-snwvh-6657c7fddb-tn8mf\"" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.360111   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0729 13:32:20.360151   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.372196   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snwvh-6657c7fddb-jjwvk\"" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" 
I0729 13:32:20.450307   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0729 13:32:20.450395   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" 
I0729 13:32:20.463124   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snwvh-cdfc6fd6c-4rwlx\"" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" 
E0729 13:32:20.671381   10532 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-snwvh-cdfc6fd6c-4rwlx-2mnld for machine md-test/md-snwvh-cdfc6fd6c-4rwlx: the cache is not started, can not read objects" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" 
I0729 13:32:20.701510   10532 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0729 13:32:20.701563   10532 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0729 13:32:20.705571   10532 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "machine"="md-snwvh-6657c7fddb-tn8mf"
I0729 13:32:20.816502   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0729 13:32:20.816556   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" 
I0729 13:32:20.828125   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snwvh-cdfc6fd6c-w2464\"" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" 
I0729 13:32:20.928189   10532 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0729 13:32:20.928232   10532 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0729 13:32:20.932396   10532 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "machine"="md-snwvh-6657c7fddb-kw94n"
E0729 13:32:20.994296   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
I0729 13:32:21.042656   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0729 13:32:21.042701   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" 
I0729 13:32:21.053662   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snwvh-cdfc6fd6c-l42mj\"" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" 
I0729 13:32:21.160614   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-794x2" "machine"="test6-dd8m2" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"3ab048db-e745-473a-b9cb-ef31cfb2862b","apiVersion":"v1"}
E0729 13:32:21.161570   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dd8m2\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dd8m2" "namespace"="default"
I0729 13:32:21.198921   10532 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0729 13:32:21.198964   10532 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0729 13:32:21.204127   10532 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snwvh-6657c7fddb" "namespace"="md-test" "machine"="md-snwvh-6657c7fddb-jjwvk"
I0729 13:32:21.339781   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0729 13:32:21.339818   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-snwvh-74d45c49c5" "namespace"="md-test" 
I0729 13:32:21.353529   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snwvh-74d45c49c5-mhvsf\"" "machineset"="md-snwvh-74d45c49c5" "namespace"="md-test" 
... skipping 6 lines ...
I0729 13:32:21.705403   10532 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0729 13:32:21.705520   10532 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0729 13:32:21.711413   10532 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snwvh-cdfc6fd6c" "namespace"="md-test" "machine"="md-snwvh-cdfc6fd6c-4rwlx"
I0729 13:32:21.733309   10532 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snwvh-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0729 13:32:21.733408   10532 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-snwvh-74d45c49c5" "namespace"="md-test" 
I0729 13:32:21.743868   10532 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snwvh-74d45c49c5-gt62w\"" "machineset"="md-snwvh-74d45c49c5" "namespace"="md-test" 
E0729 13:32:21.954738   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
•E0729 13:32:21.966309   10532 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-snwvh-74d45c49c5-d6zct-dp6ll for machine md-test/md-snwvh-74d45c49c5-d6zct: the cache is not started, can not read objects" "machineset"="md-snwvh-74d45c49c5" "namespace"="md-test" 
E0729 13:32:21.966434   10532 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found"  "cluster"="md-test/test-cluster"
I0729 13:32:21.995026   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-794x2" "namespace"="default" "count"=1
I0729 13:32:21.995099   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-794x2" "namespace"="default" "descendants"="Control plane machines: test6-dd8m2" "indirect descendants count"=0
E0729 13:32:22.000190   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
E0729 13:32:22.162168   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-qqcjr\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-qqcjr" "namespace"="md-test"
E0729 13:32:23.001042   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:23.162891   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-cdfc6fd6c-w2464\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-cdfc6fd6c-w2464" "namespace"="md-test"
I0729 13:32:24.013815   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-794x2" "namespace"="default" "count"=1
I0729 13:32:24.013876   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-794x2" "namespace"="default" "descendants"="Control plane machines: test6-dd8m2" "indirect descendants count"=0
E0729 13:32:24.014401   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:24.163427   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-lc8xn\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-lc8xn" "namespace"="md-test"
E0729 13:32:25.015140   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
I0729 13:32:25.164022   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-794x2" "machine"="test6-dd8m2" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"3ab048db-e745-473a-b9cb-ef31cfb2862b","apiVersion":"v1"}
E0729 13:32:25.164662   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dd8m2\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dd8m2" "namespace"="default"
E0729 13:32:26.016122   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:26.165111   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-mhvsf\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-mhvsf" "namespace"="md-test"
E0729 13:32:27.016931   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:27.165612   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-d6zct\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-d6zct" "namespace"="md-test"
I0729 13:32:28.017761   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-794x2" "namespace"="default" "count"=1
I0729 13:32:28.017840   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-794x2" "namespace"="default" "descendants"="Control plane machines: test6-dd8m2" "indirect descendants count"=0
E0729 13:32:28.018533   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
E0729 13:32:28.166225   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-gt62w\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-gt62w" "namespace"="md-test"
E0729 13:32:29.019433   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:29.166849   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-qqcjr\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-qqcjr" "namespace"="md-test"
E0729 13:32:30.167284   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-cdfc6fd6c-w2464\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-cdfc6fd6c-w2464" "namespace"="md-test"
E0729 13:32:31.167701   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-lc8xn\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-lc8xn" "namespace"="md-test"
E0729 13:32:31.580085   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
I0729 13:32:32.168322   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-794x2" "machine"="test6-dd8m2" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"3ab048db-e745-473a-b9cb-ef31cfb2862b","apiVersion":"v1"}
E0729 13:32:32.169006   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dd8m2\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dd8m2" "namespace"="default"
I0729 13:32:33.018655   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-794x2" "namespace"="default" "count"=1
I0729 13:32:33.018791   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-794x2" "namespace"="default" "descendants"="Control plane machines: test6-dd8m2" "indirect descendants count"=0
E0729 13:32:33.139355   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
E0729 13:32:33.169565   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-mhvsf\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-mhvsf" "namespace"="md-test"
E0729 13:32:34.170255   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-d6zct\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-d6zct" "namespace"="md-test"
E0729 13:32:35.170824   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-gt62w\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-gt62w" "namespace"="md-test"
E0729 13:32:36.171210   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-qqcjr\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-qqcjr" "namespace"="md-test"
E0729 13:32:36.700743   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
E0729 13:32:37.171756   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-cdfc6fd6c-w2464\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-cdfc6fd6c-w2464" "namespace"="md-test"
I0729 13:32:38.019684   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-794x2" "namespace"="default" "count"=1
I0729 13:32:38.019807   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-794x2" "namespace"="default" "descendants"="Control plane machines: test6-dd8m2" "indirect descendants count"=0
E0729 13:32:38.172261   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-lc8xn\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-lc8xn" "namespace"="md-test"
I0729 13:32:39.172850   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-794x2" "machine"="test6-dd8m2" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"3ab048db-e745-473a-b9cb-ef31cfb2862b","apiVersion":"v1"}
E0729 13:32:39.173686   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dd8m2\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dd8m2" "namespace"="default"
E0729 13:32:40.174367   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-mhvsf\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-mhvsf" "namespace"="md-test"
E0729 13:32:41.174902   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-d6zct\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-d6zct" "namespace"="md-test"
E0729 13:32:42.175525   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-gt62w\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-gt62w" "namespace"="md-test"
I0729 13:32:43.020532   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-794x2" "namespace"="default" "count"=1
I0729 13:32:43.020622   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-794x2" "namespace"="default" "descendants"="Control plane machines: test6-dd8m2" "indirect descendants count"=0
E0729 13:32:43.176142   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-qqcjr\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-qqcjr" "namespace"="md-test"
E0729 13:32:43.380279   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-kp6ch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-kp6ch" "namespace"="default"
E0729 13:32:44.176536   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-s9z4t\" for machine \"test-mhc-machine-6mwbg\" in namespace \"test-mhc-l8s5x\": Cluster.cluster.x-k8s.io \"test-cluster-s9z4t\" not found" "controller"="machine" "name"="test-mhc-machine-6mwbg" "namespace"="test-mhc-l8s5x"
E0729 13:32:45.177028   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-cdfc6fd6c-w2464\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-cdfc6fd6c-w2464" "namespace"="md-test"
E0729 13:32:46.177477   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-lc8xn\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-lc8xn" "namespace"="md-test"
E0729 13:32:46.941558   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-drkbd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-drkbd" "namespace"="default"
I0729 13:32:47.178145   10532 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-794x2" "machine"="test6-dd8m2" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"3ab048db-e745-473a-b9cb-ef31cfb2862b","apiVersion":"v1"}
E0729 13:32:47.178862   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dd8m2\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dd8m2" "namespace"="default"
I0729 13:32:48.021761   10532 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-794x2" "namespace"="default" "count"=1
I0729 13:32:48.021852   10532 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-794x2" "namespace"="default" "descendants"="Control plane machines: test6-dd8m2" "indirect descendants count"=0
E0729 13:32:48.179301   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-mhvsf\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-mhvsf" "namespace"="md-test"
E0729 13:32:49.179805   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-d6zct\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-d6zct" "namespace"="md-test"
E0729 13:32:50.180360   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-74d45c49c5-gt62w\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-74d45c49c5-gt62w" "namespace"="md-test"
E0729 13:32:51.180887   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"md-snwvh-6657c7fddb-qqcjr\" in namespace \"md-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="md-snwvh-6657c7fddb-qqcjr" "namespace"="md-test"

------------------------------
• Failure [30.069 seconds]
MachineSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/machineset_controller_test.go:47
  Should reconcile a MachineSet [It]
... skipping 14 lines ...
STEP: Deleting the namespace



Summarizing 1 Failure:

[Fail] MachineSet Reconciler [It] Should reconcile a MachineSet 
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/machineset_controller_test.go:172

Ran 16 of 16 Specs in 45.619 seconds
FAIL! -- 15 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestGinkgoSuite (45.62s)
FAIL
Tearing down test suite
E0729 13:32:52.027287   10532 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 13:32:52.027313   10532 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-688519371/tls.crt: no such file or directory"  
E0729 13:32:52.027327   10532 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 13:32:52.027344   10532 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-688519371/tls.crt: no such file or directory"  
I0729 13:32:52.027756   10532 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0729 13:32:52.027816   10532 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0729 13:32:52.027871   10532 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0729 13:32:52.027882   10532 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0729 13:32:52.027892   10532 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0729 13:32:52.027900   10532 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0729 13:32:52.027900   10532 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
E0729 13:32:52.031809   10532 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[Internal error occurred: failed calling webhook \"default.cluster.cluster.x-k8s.io\": Post https://127.0.0.1:41471/mutate-cluster-x-k8s-io-v1alpha3-cluster?timeout=30s: dial tcp 127.0.0.1:41471: connect: connection refused, Patch http://127.0.0.1:45709/apis/cluster.x-k8s.io/v1alpha3/namespaces/ms-test/clusters/test-cluster/status: dial tcp 127.0.0.1:45709: connect: connection refused]" "controller"="cluster" "name"="test-cluster" "namespace"="ms-test"
E0729 13:32:52.071297   10532 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:45709/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1210&timeout=10s&timeoutSeconds=522&watch=true: dial tcp 127.0.0.1:45709: connect: connection refused
FAIL	sigs.k8s.io/cluster-api/controllers	89.752s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
--- PASS: TestCloneTemplateResourceNotFound (0.00s)
... skipping 264 lines ...
•I0729 13:31:34.279270   10939 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0729 13:31:34.293126   10939 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":{}}}
I0729 13:31:34.393604   10939 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0729 13:31:34.393693   10939 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0729 13:31:34.444673   10939 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0729 13:31:34.877770   10939 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0729 13:31:36.941592   10939 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-9ltzd/test-cluster"
•E0729 13:31:37.397505   10939 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-tj557/test-cluster"
•E0729 13:31:38.004518   10939 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:46555/?timeout=50ms: dial tcp 127.0.0.1:46555: connect: connection refused"  "cluster"="cluster-cache-test-hsfdg/test-cluster"
•I0729 13:31:38.235875   10939 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0729 13:31:38.347873   10939 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:34957/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:34957: connect: connection refused


Ran 5 of 5 Specs in 14.699 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (14.70s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	14.885s
?   	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
I0729 13:31:44.700802   11588 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
E0729 13:31:44.701950   11588 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
I0729 13:31:44.703118   11588 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0729 13:31:44.703243   11588 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
I0729 13:31:56.187145   11588 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
I0729 13:31:56.187308   11588 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: 1627565493
Will run 1 of 1 specs

E0729 13:31:56.216421   11588 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-bdovz6\" not found" "kubeadmControlPlane"="kcp-foo-bdovz6" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.026 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.03s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0729 13:31:56.218067   11588 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-9bnsvo" "kubeadmControlPlane"="kcp-foo-9bnsvo" "namespace"="test" 
I0729 13:31:57.199941   11588 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-9bnsvo" "kubeadmControlPlane"="kcp-foo-9bnsvo" "namespace"="test" "needRollout"=["kcp-foo-9bnsvo-45lf2"]
I0729 13:31:57.200058   11588 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-9bnsvo" "kubeadmControlPlane"="kcp-foo-9bnsvo" "namespace"="test" "failures"="[machine kcp-foo-9bnsvo-vmpqr does not have APIServerPodHealthy condition, machine kcp-foo-9bnsvo-vmpqr does not have ControllerManagerPodHealthy condition, machine kcp-foo-9bnsvo-vmpqr does not have SchedulerPodHealthy condition, machine kcp-foo-9bnsvo-vmpqr does not have EtcdPodHealthy condition, machine kcp-foo-9bnsvo-vmpqr does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (0.98s)
... skipping 60 lines ...
==================================
Random Seed: 1627565492
Will run 7 of 7 specs

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

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0729 13:31:45.003840   11566 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"  
E0729 13:31:53.326884   11566 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"  
E0729 13:32:02.312900   11566 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"  
E0729 13:32:13.443238   11566 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"  
E0729 13:32:29.916460   11566 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"  
E0729 13:32:42.925232   11566 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"  
E0729 13:33:00.572682   11566 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"  
E0729 13:33:21.496137   11566 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"  
E0729 13:33:52.512664   11566 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"  
E0729 13:34:37.669863   11566 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
E0729 13:34:37.677407   11566 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 13:34:37.677434   11566 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-249857418/tls.crt: no such file or directory"  
E0729 13:34:37.677448   11566 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 13:34:37.677461   11566 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-249857418/tls.crt: no such file or directory"  
I0729 13:34:37.678036   11566 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	185.342s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0729 13:31:51.443811   11876 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0729 13:31:51.546743   11876 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0729 13:31:51.550549   11876 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0729 13:31:51.647198   11876 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0729 13:31:51.647285   11876 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0729 13:31:51.725053   11876 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-i6wt5b"} 
E0729 13:31:51.752126   11876 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"
•I0729 13:31:52.810460   11876 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-kye3ka"} 
E0729 13:31:52.891266   11876 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"
•E0729 13:31:53.990370   11876 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"
E0729 13:31:55.017097   11876 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"
•E0729 13:31:56.204125   11876 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"
•E0729 13:31:57.245834   11876 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"
•E0729 13:31:58.263405   11876 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 13:31:58.263475   11876 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-094947101/tls.crt: no such file or directory"  
E0729 13:31:58.263493   11876 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 13:31:58.263506   11876 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-094947101/tls.crt: no such file or directory"  
I0729 13:31:58.263555   11876 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0729 13:31:58.263600   11876 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0729 13:31:58.263712   11876 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0729 13:31:58.265542   11876 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"


Ran 5 of 5 Specs in 18.509 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (18.51s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	18.589s
?   	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
E0729 13:31:44.694296   12131 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 91 lines ...
•I0729 13:31:54.397494   12131 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0729 13:31:54.428005   12131 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0729 13:31:54.446705   12131 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0729 13:31:54.448425   12131 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0729 13:31:54.485035   12131 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0729 13:31:54.518848   12131 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0729 13:31:54.521337   12131 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 13:31:54.521372   12131 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-113045159/tls.crt: no such file or directory"  
I0729 13:31:54.521497   12131 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0729 13:31:54.521712   12131 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0729 13:31:54.521734   12131 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-113045159/tls.crt: no such file or directory"  


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


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