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

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I0609 14:40:34.310095    8403 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0609 14:40:34.310308    8403 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0609 14:40:34.311272    8403 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0609 14:40:34.311482    8403 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=36035
I0609 14:40:34.312450    8403 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0609 14:40:35.070760    8403 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" 
•E0609 14:40:35.079875    8403 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 14:40:35.079916    8403 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-179435357/tls.crt: no such file or directory"  
I0609 14:40:35.080007    8403 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 12.611 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (12.61s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	41.492s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0609 14:40:25.862290   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0609 14:40:25.862725   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
I0609 14:40:25.863200   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0609 14:40:25.863224   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
I0609 14:40:25.863554   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0609 14:40:25.863761   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
2022/06/09 14:40:26 http: TLS handshake error from 127.0.0.1:41320: 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
I0609 14:40:26.161883   10504 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"
I0609 14:40:26.164971   10504 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
I0609 14:40:26.192424   10504 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
I0609 14:40:26.193865   10504 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"
E0609 14:40:26.194154   10504 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
I0609 14:40:26.194560   10504 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0609 14:40:26.433667   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0609 14:40:26.436056   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0609 14:40:26.442159   10504 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-bxh4c" "namespace"="test-machine-watches-ngh56" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0609 14:40:26.442241   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0609 14:40:26.567635   10504 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-bxh4c" "namespace"="test-machine-watches-ngh56" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0609 14:40:26.567737   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0609 14:40:26.668289   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-bxh4c" "namespace"="test-machine-watches-ngh56" "noderef"="node-1"
E0609 14:40:26.675680   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0609 14:40:26.675729   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0609 14:40:26.722322   10504 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-bxh4c\" in namespace \"test-machine-watches-ngh56\", requeuing: requeue in 1s"  
E0609 14:40:26.742267   10504 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-bxh4c\" in namespace \"test-machine-watches-ngh56\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-bxh4c\" in namespace \"test-machine-watches-ngh56\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-bxh4c" "namespace"="test-machine-watches-ngh56"
--- PASS: TestWatches (0.58s)
=== 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
I0609 14:40:26.873087   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-7twjw" "namespace"="test-machine-watches-ngh56" "count"=1
I0609 14:40:26.873151   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-7twjw" "namespace"="test-machine-watches-ngh56" "descendants"="Worker machines: machine-created-bxh4c" "indirect descendants count"=0
I0609 14:40:26.887817   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-7twjw" "namespace"="test-machine-watches-ngh56" "count"=1
I0609 14:40:26.887883   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-7twjw" "namespace"="test-machine-watches-ngh56" "descendants"="Worker machines: machine-created-bxh4c" "indirect descendants count"=0
I0609 14:40:27.743551   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-7twjw" "machine"="machine-created-bxh4c" "namespace"="test-machine-watches-ngh56" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"85f6cc4e-2c41-45f8-a5f4-31281e8fd2a2","apiVersion":"v1"}
E0609 14:40:27.812337   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-bxh4c\" not found" "controller"="machine" "name"="machine-created-bxh4c" "namespace"="test-machine-watches-ngh56"
E0609 14:40:28.858092   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-h5868\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-svvvz\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-svvvz: secrets \"machine-reconcile-svvvz-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-h5868" "namespace"="default"
I0609 14:40:29.858706   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-svvvz" "machine"="machine-created-h5868" "namespace"="default" "cause"="noderef is nil" "node"=null
I0609 14:40:29.894168   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-svvvz" "machine"="machine-created-h5868" "namespace"="default" "cause"="noderef is nil" "node"=null
I0609 14:40:29.915966   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-svvvz" "machine"="machine-created-h5868" "namespace"="default" "cause"="noderef is nil" "node"=null
E0609 14:40:29.968291   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-h5868\" not found" "controller"="machine" "name"="machine-created-h5868" "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)
... skipping 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0609 14:40:30.019102   10504 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0609 14:40:30.019576   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-svvvz\" not found" "controller"="cluster" "name"="machine-reconcile-svvvz" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0609 14:40:30.024087   10504 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0609 14:40:30.044682   10504 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.03s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.00s)
... skipping 111 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0609 14:40:30.382353   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-52qvd" "namespace"="test-mhc-nb8sp" 
I0609 14:40:30.398372   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0609 14:40:30.402873   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-nb8sp/test-cluster-59j7v"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0609 14:40:30.415011   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-52qvd\" not found" "controller"="machinehealthcheck" "name"="test-mhc-52qvd" "namespace"="test-mhc-nb8sp"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0609 14:40:31.415328   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-52qvd" "namespace"="test-mhc-nb8sp" 
I0609 14:40:31.415471   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rkzlh" "namespace"="test-mhc-5f2sz" 
I0609 14:40:31.415515   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kzdcl" "namespace"="test-mhc-zjjh6" 
I0609 14:40:31.415553   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nfls5" "namespace"="test-mhc-qg8x4" 
I0609 14:40:31.442144   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 14:40:31.560923   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nfls5" "namespace"="test-mhc-qg8x4" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0609 14:40:31.622828   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nfls5" "namespace"="test-mhc-qg8x4" 
E0609 14:40:31.645061   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qg8x4/test-cluster-kzktf"
E0609 14:40:31.647658   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-kzktf\" not found" "controller"="cluster" "name"="test-cluster-kzktf" "namespace"="test-mhc-qg8x4"
I0609 14:40:31.772391   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s2msh" "namespace"="test-mhc-xg4jn" 
I0609 14:40:31.797205   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 14:40:31.823504   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s2msh" "namespace"="test-mhc-xg4jn" 
I0609 14:40:31.836511   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s2msh" "namespace"="test-mhc-xg4jn" 
E0609 14:40:31.882173   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xg4jn/test-cluster-gpw9j"
I0609 14:40:31.887267   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s2msh" "namespace"="test-mhc-xg4jn" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0609 14:40:31.911135   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
inframachine created: test-mhc-machine-infra-cn5m7
I0609 14:40:31.949018   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-slm8n
I0609 14:40:31.980387   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:31.987825   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:31.989276   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:31.989607   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.005273   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.005927   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.008280   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.011087   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.018804   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.019136   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.035272   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.035584   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.048885   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.049222   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.055314   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.055693   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
E0609 14:40:32.066438   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-8bnf7"
E0609 14:40:32.066438   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8bnf7, got []"  "node"="test-mhc-node-8bnf7"
node created: test-mhc-node-8bnf7
I0609 14:40:32.071485   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-slm8n" "namespace"="test-mhc-kjpgh" "noderef"="test-mhc-node-8bnf7"
E0609 14:40:32.075860   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8bnf7, got []"  "node"="test-mhc-node-8bnf7"
E0609 14:40:32.075908   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8bnf7, got []"  "node"="test-mhc-node-8bnf7"
E0609 14:40:32.076111   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-8bnf7"
E0609 14:40:32.076143   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-8bnf7"
I0609 14:40:32.079548   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
inframachine created: test-mhc-machine-infra-94jv8
machine created: test-mhc-machine-5p6ns
I0609 14:40:32.099478   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.105517   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.106720   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
... skipping 37 lines ...
I0609 14:40:32.230835   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.232395   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.234035   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.235833   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.237107   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.240499   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.240891   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-5p6ns/"
I0609 14:40:32.263788   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.264435   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-5p6ns/"
I0609 14:40:32.265719   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.266286   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-5p6ns/"
I0609 14:40:32.290028   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.290546   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-5p6ns/"
I0609 14:40:32.302717   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.303205   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-5p6ns/"
node created: test-mhc-node-q6cz8
E0609 14:40:32.305812   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q6cz8, got []"  "node"="test-mhc-node-q6cz8"
E0609 14:40:32.306036   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-q6cz8"
I0609 14:40:32.307866   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.308496   10504 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-kjpgh/test-mhc-sflxq/test-mhc-machine-5p6ns/"
I0609 14:40:32.314306   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.333064   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
Cleaning up nodes, machines and infra machines.
I0609 14:40:32.336352   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.339402   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.339828   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.353333   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-gqwqp" "machine"="test-mhc-machine-slm8n" "namespace"="test-mhc-kjpgh" "cause"="no control plane members" "node"={"kind":"Node","name":"test-mhc-node-8bnf7","uid":"0ca1187d-07c0-4fbe-bea8-3a6981133546","apiVersion":"v1"}
I0609 14:40:32.372460   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:32.373009   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kjpgh/test-mhc-sflxq/test-mhc-machine-slm8n/"
I0609 14:40:32.373476   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kjpgh/test-mhc-sflxq/test-mhc-machine-5p6ns/"
E0609 14:40:32.394702   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kjpgh/test-cluster-gqwqp"
I0609 14:40:32.398543   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
E0609 14:40:32.398644   10504 machinehealthcheck_controller.go:128] controllers/MachineHealthCheck "msg"="Failed to fetch Cluster for MachineHealthCheck" "error"="Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "cluster"="test-cluster-gqwqp" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
E0609 14:40:32.398688   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machinehealthcheck" "name"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0609 14:40:32.413853   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-slm8n\" not found" "controller"="machine" "name"="test-mhc-machine-slm8n" "namespace"="test-mhc-kjpgh"
inframachine created: test-mhc-machine-infra-d9jwz
machine created: test-mhc-machine-qcprr
E0609 14:40:32.660543   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-ngh56/machine-reconcile-7twjw"
I0609 14:40:33.398950   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sflxq" "namespace"="test-mhc-kjpgh" 
I0609 14:40:33.399047   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
E0609 14:40:33.417884   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:33.423338   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 14:40:33.446918   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:33.452901   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:33.454415   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:33.456304   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:33.458065   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
... skipping 413 lines ...
I0609 14:40:34.422334   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:34.424187   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:34.425878   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:34.426438   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:34.427555   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:34.429868   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
E0609 14:40:34.431398   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:34.431549   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:34.431776   10504 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-7jmmd/test-mhc-mrzkc/test-mhc-machine-qcprr/"
I0609 14:40:34.441455   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:34.441767   10504 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-7jmmd/test-mhc-mrzkc/test-mhc-machine-qcprr/"
E0609 14:40:34.454301   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tkdzs, got []"  "node"="test-mhc-node-tkdzs"
node created: test-mhc-node-tkdzs
I0609 14:40:34.461446   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
inframachine created: test-mhc-machine-infra-bllqh
I0609 14:40:34.485161   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
machine created: test-mhc-machine-kls28
I0609 14:40:34.491930   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
... skipping 355 lines ...
I0609 14:40:35.479575   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.483377   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.484985   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.487634   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.490055   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.490996   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
E0609 14:40:35.492525   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:35.493039   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.495112   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.497341   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.499423   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.501500   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:35.507802   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
... skipping 375 lines ...
I0609 14:40:36.498842   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.501504   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.502487   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.504655   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.506713   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.508690   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.509025   10504 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-7jmmd/test-mhc-mrzkc/test-mhc-machine-kls28/"
node created: test-mhc-node-86gx2
E0609 14:40:36.516862   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-86gx2, got []"  "node"="test-mhc-node-86gx2"
E0609 14:40:36.527769   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:36.528937   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.529432   10504 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-7jmmd/test-mhc-mrzkc/test-mhc-machine-kls28/"
inframachine created: test-mhc-machine-infra-llvxv
I0609 14:40:36.542170   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
machine created: test-mhc-machine-p5z67
I0609 14:40:36.570695   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.593247   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:36.594748   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
... skipping 294 lines ...
I0609 14:40:37.564574   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.566677   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.571209   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.579135   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.581205   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.584265   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
E0609 14:40:37.585764   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:37.587511   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.600502   10504 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-7jmmd/test-mhc-mrzkc/test-mhc-machine-p5z67/"
I0609 14:40:37.613526   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.614058   10504 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-7jmmd/test-mhc-mrzkc/test-mhc-machine-p5z67/"
node created: test-mhc-node-x5x4h
E0609 14:40:37.687060   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-x5x4h, got []"  "node"="test-mhc-node-x5x4h"
Cleaning up nodes, machines and infra machines.
I0609 14:40:37.694582   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.695132   10504 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-7jmmd/test-mhc-mrzkc/test-mhc-machine-p5z67/test-mhc-node-x5x4h"
Cleaning up nodes, machines and infra machines.
I0609 14:40:37.719512   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:37.720046   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7jmmd/test-mhc-mrzkc/test-mhc-machine-qcprr/"
I0609 14:40:37.749484   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7jmmd/test-mhc-mrzkc/test-mhc-machine-p5z67/"
I0609 14:40:37.759838   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9ql5m" "namespace"="test-mhc-7jmmd" "count"=2
I0609 14:40:37.759918   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9ql5m" "namespace"="test-mhc-7jmmd" "descendants"="Worker machines: test-mhc-machine-p5z67,test-mhc-machine-qcprr,test-mhc-machine-kls28" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
E0609 14:40:37.770481   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-mrzkc\" not found" "controller"="machinehealthcheck" "name"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd"
I0609 14:40:37.774699   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9ql5m" "namespace"="test-mhc-7jmmd" "count"=2
I0609 14:40:37.774753   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9ql5m" "namespace"="test-mhc-7jmmd" "descendants"="Worker machines: test-mhc-machine-qcprr,test-mhc-machine-kls28,test-mhc-machine-p5z67" "indirect descendants count"=1
inframachine created: test-mhc-machine-infra-lgn8x
machine created: test-mhc-machine-f8829
I0609 14:40:38.586296   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9ql5m" "machine"="test-mhc-machine-kls28" "namespace"="test-mhc-7jmmd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-86gx2"}
E0609 14:40:38.662674   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kls28\" not found" "controller"="machine" "name"="test-mhc-machine-kls28" "namespace"="test-mhc-7jmmd"
I0609 14:40:38.770761   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrzkc" "namespace"="test-mhc-7jmmd" 
I0609 14:40:38.770881   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:38.785457   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 14:40:38.833904   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:38.839036   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:38.860024   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:38.900995   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:38.981996   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:39.143069   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:39.464159   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:39.663356   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9ql5m" "machine"="test-mhc-machine-p5z67" "namespace"="test-mhc-7jmmd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-x5x4h"}
E0609 14:40:39.710438   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-p5z67\" not found" "controller"="machine" "name"="test-mhc-machine-p5z67" "namespace"="test-mhc-7jmmd"
I0609 14:40:40.107467   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
E0609 14:40:40.710933   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:41.388510   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:41.711521   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9ql5m" "machine"="test-mhc-machine-qcprr" "namespace"="test-mhc-7jmmd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-tkdzs"}
E0609 14:40:41.756646   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qcprr\" not found" "controller"="machine" "name"="test-mhc-machine-qcprr" "namespace"="test-mhc-7jmmd"
I0609 14:40:42.765638   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:42.769779   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
E0609 14:40:42.771014   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:42.785102   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
E0609 14:40:42.787098   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7jmmd/test-cluster-9ql5m"
E0609 14:40:42.845910   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fqs45, got []"  "node"="test-mhc-node-fqs45"
node created: test-mhc-node-fqs45
I0609 14:40:42.854635   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
inframachine created: test-mhc-machine-infra-z96bw
machine created: test-mhc-machine-gpqj5
I0609 14:40:42.877471   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:42.894047   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
... skipping 5 lines ...
I0609 14:40:43.531814   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:43.783292   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:43.789447   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:43.800981   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:43.803547   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:43.808578   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
E0609 14:40:43.813247   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:43.813342   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:43.840287   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
node created: test-mhc-node-dsj4s
E0609 14:40:43.879644   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-dsj4s, got []"  "node"="test-mhc-node-dsj4s"
I0609 14:40:43.890836   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
inframachine created: test-mhc-machine-infra-ptn7m
I0609 14:40:43.904638   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
machine created: test-mhc-machine-kswzb
I0609 14:40:43.908285   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:43.919824   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
... skipping 2 lines ...
I0609 14:40:44.826583   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:44.860404   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:44.883559   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:44.912100   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:44.916129   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:44.924317   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
E0609 14:40:44.925145   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:44.931435   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:44.958320   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
E0609 14:40:45.020363   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nj74p, got []"  "node"="test-mhc-node-nj74p"
node created: test-mhc-node-nj74p
I0609 14:40:45.032896   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
Cleaning up nodes, machines and infra machines.
I0609 14:40:45.048707   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:45.084759   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
Cleaning up nodes, machines and infra machines.
... skipping 2 lines ...
I0609 14:40:45.132139   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-75f6w" "namespace"="test-mhc-rshr8" "descendants"="Worker machines: test-mhc-machine-gpqj5,test-mhc-machine-kswzb,test-mhc-machine-f8829" "indirect descendants count"=1
I0609 14:40:45.135881   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-75f6w" "namespace"="test-mhc-rshr8" "count"=2
I0609 14:40:45.135939   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-75f6w" "namespace"="test-mhc-rshr8" "descendants"="Worker machines: test-mhc-machine-f8829,test-mhc-machine-gpqj5,test-mhc-machine-kswzb" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
inframachine created: test-mhc-machine-infra-lmqvq
machine created: test-mhc-machine-8wqmc
E0609 14:40:45.293305   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-7xb9h\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-7xb9h\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8"
I0609 14:40:45.926073   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-75f6w" "machine"="test-mhc-machine-f8829" "namespace"="test-mhc-rshr8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-fqs45"}
E0609 14:40:45.998083   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f8829\" not found" "controller"="machine" "name"="test-mhc-machine-f8829" "namespace"="test-mhc-rshr8"
I0609 14:40:46.293612   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:46.318250   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 14:40:46.337028   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7xb9h" "namespace"="test-mhc-rshr8" 
I0609 14:40:46.337089   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:47.000421   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-75f6w" "machine"="test-mhc-machine-gpqj5" "namespace"="test-mhc-rshr8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-dsj4s"}
E0609 14:40:47.040368   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gpqj5\" not found" "controller"="machine" "name"="test-mhc-machine-gpqj5" "namespace"="test-mhc-rshr8"
I0609 14:40:48.040874   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-75f6w" "machine"="test-mhc-machine-kswzb" "namespace"="test-mhc-rshr8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nj74p"}
E0609 14:40:48.097864   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kswzb\" not found" "controller"="machine" "name"="test-mhc-machine-kswzb" "namespace"="test-mhc-rshr8"
I0609 14:40:49.114194   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:49.130820   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
E0609 14:40:49.136986   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
E0609 14:40:49.190949   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8p4rb, got []"  "node"="test-mhc-node-8p4rb"
node created: test-mhc-node-8p4rb
E0609 14:40:49.191747   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8p4rb, got []"  "node"="test-mhc-node-8p4rb"
I0609 14:40:49.198769   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
inframachine created: test-mhc-machine-infra-j7cj6
I0609 14:40:49.221246   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
machine created: test-mhc-machine-jtmbj
I0609 14:40:49.252553   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:49.287895   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.154141   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.156221   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
E0609 14:40:50.158729   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rshr8/test-cluster-75f6w"
I0609 14:40:50.163053   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.173042   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.181683   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.193667   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.201097   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.227866   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
node created: test-mhc-node-d6xjg
E0609 14:40:50.233158   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d6xjg, got []"  "node"="test-mhc-node-d6xjg"
I0609 14:40:50.240840   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-jtmbj" "namespace"="test-mhc-6c8fd" "noderef"="test-mhc-node-d6xjg"
I0609 14:40:50.241893   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
inframachine created: test-mhc-machine-infra-tnr8g
machine created: test-mhc-machine-7xx82
I0609 14:40:50.261909   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.272309   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
... skipping 9 lines ...
I0609 14:40:50.561712   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.570789   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.572533   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-54pxn" "machine"="test-mhc-machine-7xx82" "namespace"="test-mhc-6c8fd" "cause"="noderef is nil" "node"=null
Cleaning up nodes, machines and infra machines.
I0609 14:40:50.578791   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.588064   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.588644   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c8fd/test-mhc-rpr9b/test-mhc-machine-8wqmc/"
I0609 14:40:50.615408   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.616106   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c8fd/test-mhc-rpr9b/test-mhc-machine-8wqmc/"
I0609 14:40:50.616609   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c8fd/test-mhc-rpr9b/test-mhc-machine-jtmbj/"
E0609 14:40:50.644352   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7xx82\" not found" "controller"="machine" "name"="test-mhc-machine-7xx82" "namespace"="test-mhc-6c8fd"
I0609 14:40:50.644773   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.645276   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c8fd/test-mhc-rpr9b/test-mhc-machine-8wqmc/"
I0609 14:40:50.645699   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c8fd/test-mhc-rpr9b/test-mhc-machine-jtmbj/"
I0609 14:40:50.658562   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-54pxn" "namespace"="test-mhc-6c8fd" "count"=2
I0609 14:40:50.658652   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-54pxn" "namespace"="test-mhc-6c8fd" "descendants"="Worker machines: test-mhc-machine-8wqmc,test-mhc-machine-jtmbj" "indirect descendants count"=0
I0609 14:40:50.661291   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:50.661778   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c8fd/test-mhc-rpr9b/test-mhc-machine-8wqmc/"
I0609 14:40:50.662223   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c8fd/test-mhc-rpr9b/test-mhc-machine-jtmbj/"
I0609 14:40:50.669613   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-54pxn" "namespace"="test-mhc-6c8fd" "count"=2
I0609 14:40:50.669684   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-54pxn" "namespace"="test-mhc-6c8fd" "descendants"="Worker machines: test-mhc-machine-8wqmc,test-mhc-machine-jtmbj" "indirect descendants count"=0
E0609 14:40:50.670575   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-rpr9b\" not found" "controller"="machinehealthcheck" "name"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd"
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-v26fn
machine created: test-mhc-machine-z46px
I0609 14:40:51.644894   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-54pxn" "machine"="test-mhc-machine-8wqmc" "namespace"="test-mhc-6c8fd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8p4rb"}
I0609 14:40:51.670827   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rpr9b" "namespace"="test-mhc-6c8fd" 
I0609 14:40:51.670919   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:51.686336   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0609 14:40:51.708775   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8wqmc\" not found" "controller"="machine" "name"="test-mhc-machine-8wqmc" "namespace"="test-mhc-6c8fd"
I0609 14:40:51.713561   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:51.715437   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:51.717214   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:51.719044   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:51.720763   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:51.722472   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
... skipping 486 lines ...
I0609 14:40:52.760545   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.762338   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.764126   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.765799   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.767496   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.770835   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
E0609 14:40:52.772269   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jtmbj\" not found" "controller"="machine" "name"="test-mhc-machine-jtmbj" "namespace"="test-mhc-6c8fd"
I0609 14:40:52.779444   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.782487   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.784650   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.786650   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.788385   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:52.790177   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
... skipping 464 lines ...
I0609 14:40:53.773837   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.775784   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.779309   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.779908   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.781061   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.783091   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
E0609 14:40:53.783972   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:53.784353   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.784621   10504 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-5sr5h/test-mhc-mrk6l/test-mhc-machine-z46px/"
I0609 14:40:53.816266   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.816645   10504 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-5sr5h/test-mhc-mrk6l/test-mhc-machine-z46px/"
E0609 14:40:53.851628   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wpcfl, got []"  "node"="test-mhc-node-wpcfl"
node created: test-mhc-node-wpcfl
E0609 14:40:53.851889   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wpcfl, got []"  "node"="test-mhc-node-wpcfl"
I0609 14:40:53.866941   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.882355   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.883562   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.889720   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.890075   10504 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-5sr5h/test-mhc-mrk6l/test-mhc-machine-z46px/test-mhc-node-wpcfl"
I0609 14:40:53.903546   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.903919   10504 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-5sr5h/test-mhc-mrk6l/test-mhc-machine-z46px/test-mhc-node-wpcfl"
I0609 14:40:53.908178   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.908565   10504 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-5sr5h/test-mhc-mrk6l/test-mhc-machine-z46px/test-mhc-node-wpcfl"
Cleaning up nodes, machines and infra machines.
I0609 14:40:53.913692   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.914050   10504 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-5sr5h/test-mhc-mrk6l/test-mhc-machine-z46px/test-mhc-node-wpcfl"
I0609 14:40:53.915337   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:53.915602   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5sr5h/test-mhc-mrk6l/test-mhc-machine-z46px/"
I0609 14:40:53.929923   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7mrps" "namespace"="test-mhc-5sr5h" "descendants"="Worker machines: test-mhc-machine-z46px" "indirect descendants count"=1
I0609 14:40:53.933981   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7mrps" "namespace"="test-mhc-5sr5h" "descendants"="Worker machines: test-mhc-machine-z46px" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0609 14:40:54.041039   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mrk6l" "namespace"="test-mhc-5sr5h" 
I0609 14:40:54.053766   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" "creating"=1 "need"=1
I0609 14:40:54.053810   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" 
I0609 14:40:54.067301   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-vxs2r-hhh8j\"" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" 
I0609 14:40:54.144866   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:54.160857   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 14:40:54.192874   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:54.784651   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7mrps" "machine"="test-mhc-machine-z46px" "namespace"="test-mhc-5sr5h" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wpcfl"}
E0609 14:40:54.830737   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-z46px\" not found" "controller"="machine" "name"="test-mhc-machine-z46px" "namespace"="test-mhc-5sr5h"
I0609 14:40:55.193075   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
E0609 14:40:55.682388   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6c8fd/test-cluster-54pxn"
I0609 14:40:55.838742   10504 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.838894   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.843791   10504 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.843922   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.861251   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.861291   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
... skipping 3 lines ...
I0609 14:40:55.883626   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.886904   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.886972   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.903885   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:55.903934   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.194124   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.194591   10504 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-tnc7x/test-mhc-7twjb/mhc-ms-vxs2r-hhh8j/"
I0609 14:40:56.202759   10504 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.206778   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.206832   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.215583   10504 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.217147   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.217475   10504 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-tnc7x/test-mhc-7twjb/mhc-ms-vxs2r-hhh8j/"
I0609 14:40:56.225749   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.225798   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.292582   10504 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-vxs2r" "namespace"="test-mhc-tnc7x" "machine"="mhc-ms-vxs2r-hhh8j"
I0609 14:40:56.294437   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fh8m9" "namespace"="test-mhc-tnc7x" "count"=1
I0609 14:40:56.294489   10504 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-fh8m9" "namespace"="test-mhc-tnc7x" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-vxs2r"
I0609 14:40:56.298437   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.298515   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fh8m9" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" "cause"="cluster is being deleted" "node"=null
I0609 14:40:56.298782   10504 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-tnc7x/test-mhc-7twjb/mhc-ms-vxs2r-hhh8j/"
I0609 14:40:56.303102   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7twjb" "namespace"="test-mhc-tnc7x" 
I0609 14:40:56.308332   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fh8m9" "namespace"="test-mhc-tnc7x" "descendants"="Machine sets: mhc-ms-vxs2r;Worker machines: mhc-ms-vxs2r-hhh8j" "indirect descendants count"=1
I0609 14:40:56.315516   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fh8m9" "namespace"="test-mhc-tnc7x" "descendants"="Worker machines: mhc-ms-vxs2r-hhh8j" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0609 14:40:56.354748   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fh8m9" "machine"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x" "cause"="cluster is being deleted" "node"=null
E0609 14:40:56.400138   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-vxs2r-hhh8j\" not found" "controller"="machine" "name"="mhc-ms-vxs2r-hhh8j" "namespace"="test-mhc-tnc7x"
I0609 14:40:56.420872   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
inframachine created: test-mhc-machine-infra-ph767
I0609 14:40:56.437334   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-4kl9m
I0609 14:40:56.554875   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:56.555624   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
... skipping 413 lines ...
I0609 14:40:57.409112   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.409710   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.414756   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.417983   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.418687   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
node created: test-mhc-node-lfnw5
E0609 14:40:57.450088   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lfnw5, got []"  "node"="test-mhc-node-lfnw5"
E0609 14:40:57.450088   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lfnw5, got []"  "node"="test-mhc-node-lfnw5"
E0609 14:40:57.450123   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lfnw5, got []"  "node"="test-mhc-node-lfnw5"
I0609 14:40:57.469727   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-4kl9m" "namespace"="test-mhc-c6zgr" "noderef"="test-mhc-node-lfnw5"
I0609 14:40:57.471515   10504 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-4kl9m" "target"="test-mhc-c6zgr/test-mhc-88b25/test-mhc-machine-4kl9m/"
I0609 14:40:57.673320   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.697725   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.712745   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.717806   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.726951   10504 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-4kl9m" "target"="test-mhc-c6zgr/test-mhc-88b25/test-mhc-machine-4kl9m/test-mhc-node-lfnw5"
I0609 14:40:57.756389   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
Cleaning up nodes, machines and infra machines.
I0609 14:40:57.761537   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.765896   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.768440   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.778215   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xtdhw" "machine"="test-mhc-machine-4kl9m" "namespace"="test-mhc-c6zgr" "cause"="no control plane members" "node"={"kind":"Node","name":"test-mhc-node-lfnw5","uid":"7374cb62-1f18-4990-9584-534c24768f29","apiVersion":"v1"}
... skipping 2 lines ...
I0609 14:40:57.781417   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xtdhw" "namespace"="test-mhc-c6zgr" "descendants"="Worker machines: test-mhc-machine-4kl9m" "indirect descendants count"=0
I0609 14:40:57.785023   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-xtdhw" "namespace"="test-mhc-c6zgr" "count"=1
I0609 14:40:57.785080   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xtdhw" "namespace"="test-mhc-c6zgr" "descendants"="Worker machines: test-mhc-machine-4kl9m" "indirect descendants count"=0
I0609 14:40:57.786677   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
I0609 14:40:57.789748   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-88b25" "namespace"="test-mhc-c6zgr" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
E0609 14:40:57.823928   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4kl9m\" not found" "controller"="machine" "name"="test-mhc-machine-4kl9m" "namespace"="test-mhc-c6zgr"
I0609 14:40:57.917108   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
inframachine created: test-mhc-machine-infra-kq2k5
I0609 14:40:57.937671   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-j4tsf
I0609 14:40:58.057219   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.058312   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
... skipping 354 lines ...
I0609 14:40:58.832069   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.834063   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.835272   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.835905   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.837577   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.839335   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.844120   10504 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-j4tsf" "target"="test-mhc-zvqm6/test-mhc-4tsqj/test-mhc-machine-j4tsf/"
node created: test-mhc-node-47mm8
E0609 14:40:58.848405   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.848617   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.848710   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.848716   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
I0609 14:40:58.855773   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-j4tsf" "namespace"="test-mhc-zvqm6" "noderef"="test-mhc-node-47mm8"
I0609 14:40:58.857418   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
E0609 14:40:58.861859   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.861908   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.862025   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.862063   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.862061   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.862065   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.862104   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
E0609 14:40:58.862109   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-47mm8, got []"  "node"="test-mhc-node-47mm8"
I0609 14:40:58.865797   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.887787   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.894186   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.900444   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.903078   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.906249   10504 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-j4tsf" "target"="test-mhc-zvqm6/test-mhc-4tsqj/test-mhc-machine-j4tsf/test-mhc-node-47mm8"
I0609 14:40:58.922818   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.934506   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
E0609 14:40:58.953985   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5sr5h/test-cluster-7mrps"
I0609 14:40:58.964330   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
Cleaning up nodes, machines and infra machines.
I0609 14:40:58.971925   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:40:58.975268   10504 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-j4tsf" "target"="test-mhc-zvqm6/test-mhc-4tsqj/test-mhc-machine-j4tsf/"
I0609 14:40:58.986842   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-gjrjr" "namespace"="test-mhc-zvqm6" "descendants"="Worker machines: test-mhc-machine-j4tsf" "indirect descendants count"=1
I0609 14:40:58.999639   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-gjrjr" "namespace"="test-mhc-zvqm6" "descendants"="Worker machines: test-mhc-machine-j4tsf" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (28.78s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.18s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.04s)
... skipping 10 lines ...
    --- PASS: TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy (3.27s)
    --- PASS: TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted (2.38s)
    --- 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.47s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (1.21s)
E0609 14:40:59.003582   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4tsqj\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6"
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0609 14:40:59.004220   10504 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
E0609 14:40:59.006085   10504 machinehealthcheck_controller.go:445]  "msg"="expected a Machine" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace
--- PASS: TestMachineToMachineHealthCheck (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace (0.00s)
=== RUN   TestNodeToMachineHealthCheck
=== RUN   TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node
E0609 14:40:59.008394   10504 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0609 14:40:59.008693   10504 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
E0609 14:40:59.009193   10504 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
I0609 14:40:59.012283   10504 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0609 14:40:59.012914   10504 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0609 14:40:59.014842   10504 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
E0609 14:40:59.027426   10504 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
E0609 14:40:59.030412   10504 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: 1654785613
Will run 16 of 16 specs

E0609 14:40:59.086816   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:40:59.255538   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-7sxg2" "namespace"="ms-test" "creating"=2 "need"=2
I0609 14:40:59.255589   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-7sxg2" "namespace"="ms-test" 
I0609 14:40:59.296360   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-7sxg2-mxwcr\"" "machineset"="ms-7sxg2" "namespace"="ms-test" 
I0609 14:40:59.296426   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-7sxg2" "namespace"="ms-test" 
I0609 14:40:59.327928   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-7sxg2-j2ss2\"" "machineset"="ms-7sxg2" "namespace"="ms-test" 
I0609 14:40:59.441718   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-7sxg2" "namespace"="ms-test" "creating"=1 "need"=2
I0609 14:40:59.441781   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-7sxg2" "namespace"="ms-test" 
I0609 14:40:59.458447   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-7sxg2-gflfq\"" "machineset"="ms-7sxg2" "namespace"="ms-test" 
E0609 14:40:59.519570   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.519570   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.521927   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.624458   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.624524   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.624658   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.624699   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.624659   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.624731   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-gflfq-66ds6, got []"  "node"="ms-7sxg2-gflfq-66ds6"
E0609 14:40:59.662818   10504 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-7sxg2-gflfq-66ds6 for machine ms-test/ms-7sxg2-gflfq: the cache is not started, can not read objects" "machineset"="ms-7sxg2" "namespace"="ms-test" 
E0609 14:40:59.673154   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.673158   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.673325   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.677278   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.677330   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.677468   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.677527   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.678477   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
E0609 14:40:59.678520   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7sxg2-j2ss2-f6mtn, got []"  "node"="ms-7sxg2-j2ss2-f6mtn"
I0609 14:40:59.799650   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7sxg2-gflfq,ms-7sxg2-j2ss2" "indirect descendants count"=2
•I0609 14:40:59.805439   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7sxg2-gflfq,ms-7sxg2-j2ss2" "indirect descendants count"=2
I0609 14:40:59.879314   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0609 14:40:59.879379   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" 
I0609 14:40:59.901066   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-9krqn-6657c7fddb-q2vhf\"" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" 
I0609 14:40:59.901129   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" 
... skipping 5 lines ...
I0609 14:40:59.985214   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-9krqn-6657c7fddb-9vdgf\"" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" 
I0609 14:41:00.003799   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4tsqj" "namespace"="test-mhc-zvqm6" 
I0609 14:41:00.077600   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0609 14:41:00.077667   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" 
I0609 14:41:00.087409   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-gjrjr" "machine"="test-mhc-machine-j4tsf" "namespace"="test-mhc-zvqm6" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-47mm8","uid":"86b1a156-95e6-4687-9d50-4485e291f3a5","apiVersion":"v1"}
I0609 14:41:00.115299   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9krqn-6657c7fddb-rl7th\"" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" 
E0609 14:41:00.143076   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j4tsf\" not found" "controller"="machine" "name"="test-mhc-machine-j4tsf" "namespace"="test-mhc-zvqm6"
I0609 14:41:00.187976   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0609 14:41:00.188031   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" 
I0609 14:41:00.204613   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9krqn-cdfc6fd6c-xcj76\"" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" 
E0609 14:41:00.287759   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.287917   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.287918   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.291950   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.292007   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.291953   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.292043   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.292198   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.292228   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-xcj76-c8xxt, got []"  "node"="md-9krqn-cdfc6fd6c-xcj76-c8xxt"
E0609 14:41:00.329083   10504 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-9krqn-cdfc6fd6c-xcj76-c8xxt for machine md-test/md-9krqn-cdfc6fd6c-xcj76: the cache is not started, can not read objects" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" 
I0609 14:41:01.314903   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0609 14:41:01.314962   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0609 14:41:01.318960   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "machine"="md-9krqn-6657c7fddb-zj8r7"
E0609 14:41:01.344027   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tnc7x/test-cluster-fh8m9"
I0609 14:41:01.418607   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:01.418657   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:01.428351   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0609 14:41:01.428407   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" 
I0609 14:41:01.443941   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9krqn-cdfc6fd6c-dcq7p\"" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" 
I0609 14:41:01.444463   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:01.444506   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:01.454184   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-6657c7fddb-zj8r7" "namespace"="md-test" "cause"="noderef is nil" "node"=null
I0609 14:41:01.491685   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-9vdgf" "namespace"="md-test" 
I0609 14:41:01.491732   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-9vdgf" "namespace"="md-test" 
I0609 14:41:01.509372   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-rl7th" "namespace"="md-test" 
I0609 14:41:01.509419   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-rl7th" "namespace"="md-test" 
E0609 14:41:01.549400   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-cdfc6fd6c-xcj76\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-xcj76" "namespace"="md-test"
E0609 14:41:01.562545   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-dcq7p-j4k8q, got []"  "node"="md-9krqn-cdfc6fd6c-dcq7p-j4k8q"
E0609 14:41:01.562944   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-dcq7p-j4k8q, got []"  "node"="md-9krqn-cdfc6fd6c-dcq7p-j4k8q"
E0609 14:41:01.687700   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-dcq7p-j4k8q, got []"  "node"="md-9krqn-cdfc6fd6c-dcq7p-j4k8q"
E0609 14:41:01.687760   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-dcq7p-j4k8q, got []"  "node"="md-9krqn-cdfc6fd6c-dcq7p-j4k8q"
E0609 14:41:01.687835   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-dcq7p-j4k8q, got []"  "node"="md-9krqn-cdfc6fd6c-dcq7p-j4k8q"
E0609 14:41:01.687895   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-dcq7p-j4k8q, got []"  "node"="md-9krqn-cdfc6fd6c-dcq7p-j4k8q"
I0609 14:41:01.746884   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0609 14:41:01.746964   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0609 14:41:01.752177   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "machine"="md-9krqn-6657c7fddb-9vdgf"
I0609 14:41:01.814045   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0609 14:41:01.814100   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" 
I0609 14:41:01.830391   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9krqn-cdfc6fd6c-9ql6g\"" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" 
E0609 14:41:01.979395   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-9ql6g-l8bwr, got []"  "node"="md-9krqn-cdfc6fd6c-9ql6g-l8bwr"
E0609 14:41:01.979395   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-9ql6g-l8bwr, got []"  "node"="md-9krqn-cdfc6fd6c-9ql6g-l8bwr"
E0609 14:41:01.983285   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-9ql6g-l8bwr, got []"  "node"="md-9krqn-cdfc6fd6c-9ql6g-l8bwr"
E0609 14:41:01.983303   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-9ql6g-l8bwr, got []"  "node"="md-9krqn-cdfc6fd6c-9ql6g-l8bwr"
E0609 14:41:01.983347   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-9ql6g-l8bwr, got []"  "node"="md-9krqn-cdfc6fd6c-9ql6g-l8bwr"
E0609 14:41:01.983355   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-cdfc6fd6c-9ql6g-l8bwr, got []"  "node"="md-9krqn-cdfc6fd6c-9ql6g-l8bwr"
I0609 14:41:02.027429   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0609 14:41:02.027476   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0609 14:41:02.036731   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9krqn-6657c7fddb" "namespace"="md-test" "machine"="md-9krqn-6657c7fddb-rl7th"
I0609 14:41:02.161390   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0609 14:41:02.161460   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" 
I0609 14:41:02.175473   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9krqn-74d45c49c5-8kp2g\"" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" 
E0609 14:41:02.255611   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-8kp2g-9x5r2, got []"  "node"="md-9krqn-74d45c49c5-8kp2g-9x5r2"
E0609 14:41:02.255973   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-8kp2g-9x5r2, got []"  "node"="md-9krqn-74d45c49c5-8kp2g-9x5r2"
E0609 14:41:02.360423   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-8kp2g-9x5r2, got []"  "node"="md-9krqn-74d45c49c5-8kp2g-9x5r2"
E0609 14:41:02.360488   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-8kp2g-9x5r2, got []"  "node"="md-9krqn-74d45c49c5-8kp2g-9x5r2"
E0609 14:41:02.360722   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-8kp2g-9x5r2, got []"  "node"="md-9krqn-74d45c49c5-8kp2g-9x5r2"
E0609 14:41:02.360759   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-8kp2g-9x5r2, got []"  "node"="md-9krqn-74d45c49c5-8kp2g-9x5r2"
I0609 14:41:02.411266   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0609 14:41:02.411320   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0609 14:41:02.415790   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "machine"="md-9krqn-cdfc6fd6c-9ql6g"
I0609 14:41:02.527913   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0609 14:41:02.527983   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" 
I0609 14:41:02.567599   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9krqn-74d45c49c5-nhcwg\"" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" 
E0609 14:41:02.602250   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-nhcwg-hhqdg, got []"  "node"="md-9krqn-74d45c49c5-nhcwg-hhqdg"
E0609 14:41:02.602626   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-nhcwg-hhqdg, got []"  "node"="md-9krqn-74d45c49c5-nhcwg-hhqdg"
I0609 14:41:02.602828   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:02.602878   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
E0609 14:41:02.606022   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-nhcwg-hhqdg, got []"  "node"="md-9krqn-74d45c49c5-nhcwg-hhqdg"
E0609 14:41:02.606065   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-nhcwg-hhqdg, got []"  "node"="md-9krqn-74d45c49c5-nhcwg-hhqdg"
E0609 14:41:02.606221   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-nhcwg-hhqdg, got []"  "node"="md-9krqn-74d45c49c5-nhcwg-hhqdg"
E0609 14:41:02.606249   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-nhcwg-hhqdg, got []"  "node"="md-9krqn-74d45c49c5-nhcwg-hhqdg"
I0609 14:41:02.624677   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:02.624730   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:02.625405   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-6657c7fddb-zj8r7" "namespace"="md-test" "cause"="noderef is nil" "node"=null
E0609 14:41:02.668190   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-9krqn-6657c7fddb-zj8r7\" not found" "controller"="machine" "name"="md-9krqn-6657c7fddb-zj8r7" "namespace"="md-test"
I0609 14:41:02.744754   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0609 14:41:02.744797   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0609 14:41:02.752825   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9krqn-cdfc6fd6c" "namespace"="md-test" "machine"="md-9krqn-cdfc6fd6c-xcj76"
I0609 14:41:02.764343   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0609 14:41:02.764395   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" 
I0609 14:41:02.778849   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9krqn-74d45c49c5-qdmwl\"" "machineset"="md-9krqn-74d45c49c5" "namespace"="md-test" 
E0609 14:41:02.806043   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-c6zgr/test-cluster-xtdhw"
E0609 14:41:02.895123   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-qdmwl-58czg, got []"  "node"="md-9krqn-74d45c49c5-qdmwl-58czg"
E0609 14:41:03.000736   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-qdmwl-58czg, got []"  "node"="md-9krqn-74d45c49c5-qdmwl-58czg"
E0609 14:41:03.000807   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9krqn-74d45c49c5-qdmwl-58czg, got []"  "node"="md-9krqn-74d45c49c5-qdmwl-58czg"
I0609 14:41:03.031718   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9krqn-cdfc6fd6c,md-9krqn-74d45c49c5;Worker machines: md-9krqn-6657c7fddb-q2vhf,md-9krqn-cdfc6fd6c-xcj76,md-9krqn-cdfc6fd6c-dcq7p,md-9krqn-74d45c49c5-8kp2g,md-9krqn-6657c7fddb-frgpq,md-9krqn-74d45c49c5-qdmwl,md-9krqn-6657c7fddb-9vdgf,md-9krqn-6657c7fddb-rl7th,md-9krqn-74d45c49c5-nhcwg" "indirect descendants count"=11
•I0609 14:41:03.034200   10504 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"
I0609 14:41:03.035356   10504 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0609 14:41:03.035429   10504 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"
I0609 14:41:03.036432   10504 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0609 14:41:03.036459   10504 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
... skipping 15 lines ...
I0609 14:41:03.048946   10504 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"
•I0609 14:41:03.050978   10504 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"
I0609 14:41:03.051941   10504 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"
I0609 14:41:03.052760   10504 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0609 14:41:03.052801   10504 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0609 14:41:03.053444   10504 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0609 14:41:03.055302   10504 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" 
••E0609 14:41:03.182191   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-q2r4k\" not found" "controller"="cluster" "name"="test1-q2r4k" "namespace"="default"
I0609 14:41:03.671702   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-6657c7fddb-9vdgf" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0609 14:41:03.705206   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-6657c7fddb-rl7th" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0609 14:41:03.812475   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-cdfc6fd6c-xcj76" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-9krqn-cdfc6fd6c-xcj76-c8xxt"}
E0609 14:41:03.953011   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-cdfc6fd6c-dcq7p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-dcq7p" "namespace"="md-test"
E0609 14:41:04.230725   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zvqm6/test-cluster-gjrjr"
•I0609 14:41:04.316545   10504 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-4x5zm" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0609 14:41:04.439801   10504 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-4x5zm" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0609 14:41:04.445429   10504 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-4x5zm" "namespace"="default"
I0609 14:41:04.971931   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:04.971980   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:04.976685   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:04.976732   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:04.977401   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-6657c7fddb-9vdgf" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0609 14:41:05.007258   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-9krqn-6657c7fddb-9vdgf\" not found" "controller"="machine" "name"="md-9krqn-6657c7fddb-9vdgf" "namespace"="md-test"
E0609 14:41:05.461502   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
•I0609 14:41:06.007783   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-6657c7fddb-rl7th" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0609 14:41:06.084696   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-9krqn-6657c7fddb-rl7th\" not found" "controller"="machine" "name"="md-9krqn-6657c7fddb-rl7th" "namespace"="md-test"
I0609 14:41:06.462029   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7sxg2-gflfq,ms-7sxg2-j2ss2" "indirect descendants count"=2
E0609 14:41:06.475383   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-ns89s\" not found" "controller"="cluster" "name"="test3-ns89s" "namespace"="default"
I0609 14:41:07.085243   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-9krqn-cdfc6fd6c-xcj76" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-9krqn-cdfc6fd6c-xcj76-c8xxt"}
E0609 14:41:07.114547   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-9krqn-cdfc6fd6c-xcj76\" not found" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-xcj76" "namespace"="md-test"
E0609 14:41:07.476148   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
E0609 14:41:08.141695   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-8kp2g\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-8kp2g" "namespace"="md-test"
E0609 14:41:08.486221   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
•E0609 14:41:09.167223   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-nhcwg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-nhcwg" "namespace"="md-test"
I0609 14:41:09.486870   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9krqn-74d45c49c5,md-9krqn-cdfc6fd6c;Worker machines: md-9krqn-6657c7fddb-frgpq,md-9krqn-74d45c49c5-qdmwl,md-9krqn-74d45c49c5-nhcwg,md-9krqn-6657c7fddb-q2vhf,md-9krqn-74d45c49c5-8kp2g,md-9krqn-cdfc6fd6c-dcq7p" "indirect descendants count"=8
E0609 14:41:09.492329   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
E0609 14:41:10.172163   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-cdfc6fd6c-dcq7p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-dcq7p" "namespace"="md-test"
E0609 14:41:10.493094   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
I0609 14:41:11.198839   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:11.198892   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:11.202686   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:11.202725   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
E0609 14:41:11.206328   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-8kp2g\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-8kp2g" "namespace"="md-test"
E0609 14:41:11.503558   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
•E0609 14:41:12.211072   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-nhcwg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-nhcwg" "namespace"="md-test"
E0609 14:41:12.504278   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
E0609 14:41:13.211524   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-gqwqp\" for machine \"test-mhc-machine-5p6ns\" in namespace \"test-mhc-kjpgh\": Cluster.cluster.x-k8s.io \"test-cluster-gqwqp\" not found" "controller"="machine" "name"="test-mhc-machine-5p6ns" "namespace"="test-mhc-kjpgh"
I0609 14:41:13.504759   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7sxg2-gflfq,ms-7sxg2-j2ss2" "indirect descendants count"=2
E0609 14:41:13.505225   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
E0609 14:41:14.217092   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-cdfc6fd6c-dcq7p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-dcq7p" "namespace"="md-test"
E0609 14:41:14.513970   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
E0609 14:41:15.226311   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-8kp2g\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-8kp2g" "namespace"="md-test"
E0609 14:41:15.514785   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
I0609 14:41:16.230760   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:16.230801   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:16.234510   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:16.234552   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
E0609 14:41:16.238699   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-nhcwg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-nhcwg" "namespace"="md-test"
I0609 14:41:16.515566   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9krqn-74d45c49c5,md-9krqn-cdfc6fd6c;Worker machines: md-9krqn-74d45c49c5-8kp2g,md-9krqn-cdfc6fd6c-dcq7p,md-9krqn-6657c7fddb-q2vhf,md-9krqn-74d45c49c5-qdmwl,md-9krqn-74d45c49c5-nhcwg,md-9krqn-6657c7fddb-frgpq" "indirect descendants count"=8
E0609 14:41:16.516219   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
E0609 14:41:17.243308   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-cdfc6fd6c-dcq7p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-dcq7p" "namespace"="md-test"
E0609 14:41:17.516938   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
E0609 14:41:18.256853   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-8kp2g\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-8kp2g" "namespace"="md-test"
E0609 14:41:18.517679   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
E0609 14:41:19.261933   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-nhcwg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-nhcwg" "namespace"="md-test"
E0609 14:41:19.518414   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
I0609 14:41:20.266284   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:20.266325   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:20.270005   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:20.270052   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
E0609 14:41:20.273760   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-cdfc6fd6c-dcq7p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-dcq7p" "namespace"="md-test"
I0609 14:41:20.518910   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7sxg2-gflfq,ms-7sxg2-j2ss2" "indirect descendants count"=2
E0609 14:41:20.519466   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
I0609 14:41:21.287356   10504 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-b7dpg" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0609 14:41:21.298110   10504 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-b7dpg" "namespace"="default" 
E0609 14:41:21.314128   10504 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-b7dpg" "namespace"="default"
E0609 14:41:21.520184   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
E0609 14:41:22.319373   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-8kp2g\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-8kp2g" "namespace"="md-test"
E0609 14:41:22.521153   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
E0609 14:41:23.324399   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-nhcwg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-nhcwg" "namespace"="md-test"
I0609 14:41:23.521756   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9krqn-74d45c49c5,md-9krqn-cdfc6fd6c;Worker machines: md-9krqn-74d45c49c5-qdmwl,md-9krqn-74d45c49c5-nhcwg,md-9krqn-6657c7fddb-frgpq,md-9krqn-74d45c49c5-8kp2g,md-9krqn-cdfc6fd6c-dcq7p,md-9krqn-6657c7fddb-q2vhf" "indirect descendants count"=8
E0609 14:41:23.522307   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
E0609 14:41:24.328998   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-cdfc6fd6c-dcq7p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-cdfc6fd6c-dcq7p" "namespace"="md-test"
E0609 14:41:24.523056   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-4x5zm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-4x5zm" "namespace"="default"
I0609 14:41:25.333761   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:25.333799   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-q2vhf" "namespace"="md-test" 
I0609 14:41:25.337617   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:25.337655   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9krqn-6657c7fddb-frgpq" "namespace"="md-test" 
I0609 14:41:25.351777   10504 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-b7dpg" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0609 14:41:25.352048   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-b7dpg" "namespace"="default" "noderef"="id-node-1"
E0609 14:41:25.365350   10504 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-b7dpg" "namespace"="default"
E0609 14:41:25.523739   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-xd5qf: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-xd5qf" "namespace"="default"
E0609 14:41:26.370063   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9krqn-74d45c49c5-8kp2g\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9krqn-74d45c49c5-8kp2g" "namespace"="md-test"
I0609 14:41:26.527857   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7sxg2-gflfq,ms-7sxg2-j2ss2" "indirect descendants count"=2

------------------------------
• [SLOW TEST:15.066 seconds]
Cluster Reconciler
I0609 14:41:26.635291   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-lvmzp" "namespace"="default" "count"=1
... skipping 2 lines ...
  /home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:248
------------------------------


Ran 16 of 16 Specs in 27.601 seconds
I0609 14:41:26.635337   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-lvmzp" "namespace"="default" "descendants"="Control plane machines: test6-b7dpg" "indirect descendants count"=0
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (27.60s)
PASS
Tearing down test suite
I0609 14:41:26.635827   10504 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0609 14:41:26.635934   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0609 14:41:26.635945   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0609 14:41:26.635970   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0609 14:41:26.635986   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0609 14:41:26.636000   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0609 14:41:26.636052   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0609 14:41:26.636329   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Patch http://127.0.0.1:43431/apis/cluster.x-k8s.io/v1alpha3/namespaces/default/clusters/test6-lvmzp/status: read tcp 127.0.0.1:43296-\u003e127.0.0.1:43431: read: connection reset by peer" "controller"="cluster" "name"="test6-lvmzp" "namespace"="default"
E0609 14:41:26.668745   10504 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:43431/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1377&timeout=10s&timeoutSeconds=522&watch=true: dial tcp 127.0.0.1:43431: connect: connection refused
E0609 14:41:26.668815   10504 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:43431/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1377&timeout=10s&timeoutSeconds=579&watch=true: dial tcp 127.0.0.1:43431: connect: connection refused
E0609 14:41:26.669118   10504 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:43431/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1377&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:43431: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	73.041s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0609 14:40:28.001758   10989 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0609 14:40:28.014180   10989 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":{}}}
I0609 14:40:28.115153   10989 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0609 14:40:28.115211   10989 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0609 14:40:28.142161   10989 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0609 14:40:28.608564   10989 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0609 14:40:30.633826   10989 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-xqd52/test-cluster"
•E0609 14:40:31.086390   10989 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-tz8fb/test-cluster"
•E0609 14:40:31.631572   10989 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:38609/?timeout=50ms: dial tcp 127.0.0.1:38609: connect: connection refused"  "cluster"="cluster-cache-test-q4tb7/test-cluster"
•I0609 14:40:31.842006   10989 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0609 14:40:31.842221   10989 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0609 14:40:31.842281   10989 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-276214253/tls.crt: no such file or directory"  
E0609 14:40:31.886228   10989 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:36043/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:36043: connect: connection refused


Ran 5 of 5 Specs in 16.182 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.18s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.363s
?   	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
I0609 14:40:40.360548   11578 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
E0609 14:40:40.361802   11578 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
I0609 14:40:40.362422   11578 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0609 14:40:40.362609   11578 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
I0609 14:40:56.243932   11578 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
I0609 14:40:56.244144   11578 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: 1654785625
Will run 1 of 1 specs

E0609 14:40:56.266793   11578 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-on3xlb\" not found" "kubeadmControlPlane"="kcp-foo-on3xlb" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.017 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0609 14:40:56.267878   11578 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-zxjeun" "kubeadmControlPlane"="kcp-foo-zxjeun" "namespace"="test" 
I0609 14:40:57.775572   11578 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-zxjeun" "kubeadmControlPlane"="kcp-foo-zxjeun" "namespace"="test" "needRollout"=["kcp-foo-zxjeun-b5k66"]
I0609 14:40:57.775764   11578 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-zxjeun" "kubeadmControlPlane"="kcp-foo-zxjeun" "namespace"="test" "failures"="[machine kcp-foo-zxjeun-mhgxt does not have APIServerPodHealthy condition, machine kcp-foo-zxjeun-mhgxt does not have ControllerManagerPodHealthy condition, machine kcp-foo-zxjeun-mhgxt does not have SchedulerPodHealthy condition, machine kcp-foo-zxjeun-mhgxt does not have EtcdPodHealthy condition, machine kcp-foo-zxjeun-mhgxt does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.51s)
PASS
I0609 14:40:57.776662   11578 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0609 14:40:57.776715   11578 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 14:40:57.776756   11578 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-916491004/tls.crt: no such file or directory"  
E0609 14:40:57.776782   11578 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 14:40:57.776804   11578 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-916491004/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	32.374s
I0609 14:40:37.167103   11550 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0609 14:40:37.167333   11550 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0609 14:40:37.167444   11550 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0609 14:40:37.168819   11550 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0609 14:40:37.168940   11550 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 52 lines ...
==================================
Random Seed: 1654785624
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1654785624
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
E0609 14:40:38.524906   11550 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"  
E0609 14:40:46.848029   11550 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"  
E0609 14:40:55.834047   11550 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"  
E0609 14:41:06.964345   11550 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"  
E0609 14:41:23.438023   11550 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"  
E0609 14:41:36.446597   11550 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"  
E0609 14:41:54.094087   11550 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"  
E0609 14:42:15.017456   11550 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"  
E0609 14:42:46.034101   11550 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"  
E0609 14:43:31.191441   11550 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
E0609 14:43:31.201094   11550 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 14:43:31.201130   11550 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-783424760/tls.crt: no such file or directory"  
E0609 14:43:31.201148   11550 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 14:43:31.201165   11550 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-783424760/tls.crt: no such file or directory"  
I0609 14:43:31.201930   11550 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	186.487s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0609 14:40:46.508273   11878 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0609 14:40:46.508956   11878 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0609 14:40:46.609450   11878 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0609 14:40:46.709851   11878 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0609 14:40:46.709923   11878 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0609 14:40:46.789513   11878 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-rm6fge"} 
E0609 14:40:46.815898   11878 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"
•I0609 14:40:47.875208   11878 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-aq0p6o"} 
•E0609 14:40:47.936904   11878 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"

------------------------------
• Failure [11.101 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0609 14:40:59.053005   11878 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"
E0609 14:41:00.249396   11878 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"
•E0609 14:41:01.274124   11878 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"
•I0609 14:41:02.287558   11878 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0609 14:41:02.287624   11878 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0609 14:41:02.287680   11878 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0609 14:41:02.288497   11878 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"



Summarizing 1 Failure:

[Fail] ClusterResourceSet Reconciler [It] Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources 
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:307

Ran 5 of 5 Specs in 28.584 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (28.58s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	28.645s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 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
E0609 14:40:39.542988   12152 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 92 lines ...
•I0609 14:40:50.542057   12152 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0609 14:40:50.584882   12152 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0609 14:40:50.589199   12152 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0609 14:40:50.647321   12152 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0609 14:40:50.687412   12152 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0609 14:40:50.716455   12152 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0609 14:40:50.720782   12152 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 14:40:50.720844   12152 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-317902325/tls.crt: no such file or directory"  
E0609 14:40:50.720878   12152 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 14:40:50.720902   12152 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-317902325/tls.crt: no such file or directory"  
I0609 14:40:50.721045   12152 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 11.200 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.20s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.432s
?   	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 201 lines ...
I0609 14:41:13.675798   15079 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0609 14:41:13.676011   15079 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0609 14:41:13.676684   15079 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0609 14:41:13.676928   15079 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39153
I0609 14:41:13.676989   15079 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I0609 14:41:14.412101   15079 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0609 14:41:14.412165   15079 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0609 14:41:14.412240   15079 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-578466676/tls.crt: no such file or directory"  


Ran 14 of 14 Specs in 6.882 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (6.88s)
=== 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.041s
FAIL
make: *** [Makefile:116: test] Error 1