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

No Test Failures!


Error lines from build-log.txt

... skipping 781 lines ...
I0729 09:31:24.686650    8415 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0729 09:31:25.223898    8415 kubeadmconfig_controller.go:223]  "msg"="Cluster infrastructure is not ready, waiting" "kind"="Machine" "kubeadmconfig"={"Namespace":"default","Name":"my-machine-config"} "name"="my-machine" "version"="109" 
•I0729 09:31:25.235176    8415 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.156 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.16s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	64.359s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 310 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.01s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0729 09:30:55.497982   10526 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0729 09:30:55.498033   10526 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0729 09:30:55.498447   10526 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0729 09:30:55.498482   10526 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0729 09:30:55.498520   10526 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0729 09:30:55.498557   10526 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
2021/07/29 09:30:55 http: TLS handshake error from 127.0.0.1:59576: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0729 09:30:55.697687   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
I0729 09:30:55.700797   10526 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.01s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0729 09:30:55.751336   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed
I0729 09:30:55.754234   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0729 09:30:55.754999   10526 machine_controller_phases.go:246]  "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-test\" in namespace \"default\", requeuing: requeue in 1s"  
=== RUN   TestReconcileInfrastructure/infrastructure_ref_is_paused
I0729 09:30:55.756109   10526 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.01s)
    --- 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
I0729 09:30:56.055166   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0729 09:30:56.155822   10526 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0729 09:30:56.165594   10526 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-dx524" "namespace"="test-machine-watches-bc5bb" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0729 09:30:56.165711   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0729 09:30:56.275373   10526 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-dx524" "namespace"="test-machine-watches-bc5bb" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0729 09:30:56.275467   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0729 09:30:56.376046   10526 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-dx524" "namespace"="test-machine-watches-bc5bb" "noderef"="node-1"
E0729 09:30:56.386683   10526 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0729 09:30:56.386735   10526 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0729 09:30:56.425503   10526 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-dx524\" in namespace \"test-machine-watches-bc5bb\", requeuing: requeue in 1s"  
E0729 09:30:56.442238   10526 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-dx524\" in namespace \"test-machine-watches-bc5bb\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-dx524\" in namespace \"test-machine-watches-bc5bb\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-dx524" "namespace"="test-machine-watches-bc5bb"
--- PASS: TestWatches (0.72s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I0729 09:30:56.665903   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-t78t6" "namespace"="test-machine-watches-bc5bb" "count"=1
I0729 09:30:56.665971   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-t78t6" "namespace"="test-machine-watches-bc5bb" "descendants"="Worker machines: machine-created-dx524" "indirect descendants count"=0
I0729 09:30:56.684289   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-t78t6" "namespace"="test-machine-watches-bc5bb" "count"=1
I0729 09:30:56.684365   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-t78t6" "namespace"="test-machine-watches-bc5bb" "descendants"="Worker machines: machine-created-dx524" "indirect descendants count"=0
I0729 09:30:57.443015   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-t78t6" "machine"="machine-created-dx524" "namespace"="test-machine-watches-bc5bb" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"cbca80e8-50bd-4f3f-9cd7-9387e4409e10","apiVersion":"v1"}
E0729 09:30:57.501979   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-dx524\" not found" "controller"="machine" "name"="machine-created-dx524" "namespace"="test-machine-watches-bc5bb"
E0729 09:30:58.571593   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-p9l6f\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-898zg\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-898zg: secrets \"machine-reconcile-898zg-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-p9l6f" "namespace"="default"
I0729 09:30:59.572150   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-898zg" "machine"="machine-created-p9l6f" "namespace"="default" "cause"="noderef is nil" "node"=null
I0729 09:30:59.618030   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-898zg" "machine"="machine-created-p9l6f" "namespace"="default" "cause"="noderef is nil" "node"=null
I0729 09:30:59.641831   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-898zg" "machine"="machine-created-p9l6f" "namespace"="default" "cause"="noderef is nil" "node"=null
E0729 09:30:59.710815   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-p9l6f\" not found" "controller"="machine" "name"="machine-created-p9l6f" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.25s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.25s)
=== 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 5 lines ...
I0729 09:30:59.732774   10526 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0729 09:30:59.738580   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0729 09:30:59.738984   10526 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0729 09:30:59.744116   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0729 09:30:59.747028   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-898zg\" not found" "controller"="cluster" "name"="machine-reconcile-898zg" "namespace"="default"
I0729 09:30:59.761985   10526 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.03s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.01s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.02s)
=== RUN   TestReconcileRequest
... skipping 120 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0729 09:31:00.040528   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-79gh9" "namespace"="test-mhc-7ztx9" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0729 09:31:00.073761   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0729 09:31:00.073832   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-8fn46\" not found"  "cluster"="test-mhc-7ztx9/test-cluster-8fn46"
=== 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
E0729 09:31:00.185088   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-79gh9\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-79gh9\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-79gh9" "namespace"="test-mhc-7ztx9"
I0729 09:31:01.185440   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z78w7" "namespace"="test-mhc-rwq55" 
I0729 09:31:01.185568   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-n6rnt" "namespace"="test-mhc-bvv7m" 
I0729 09:31:01.185603   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-79gh9" "namespace"="test-mhc-7ztx9" 
I0729 09:31:01.185633   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rf9x" "namespace"="test-mhc-rmq9j" 
I0729 09:31:01.204363   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 09:31:01.232435   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rf9x" "namespace"="test-mhc-rmq9j" 
I0729 09:31:01.242277   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rf9x" "namespace"="test-mhc-rmq9j" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0729 09:31:01.251966   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rmq9j/test-cluster-sk6zf"
E0729 09:31:01.253530   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-sk6zf\" not found" "controller"="cluster" "name"="test-cluster-sk6zf" "namespace"="test-mhc-rmq9j"
I0729 09:31:01.261174   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xsl8s" "namespace"="test-mhc-b62sg" 
I0729 09:31:01.298482   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 09:31:01.316750   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xsl8s" "namespace"="test-mhc-b62sg" 
I0729 09:31:01.321403   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xsl8s" "namespace"="test-mhc-b62sg" 
E0729 09:31:01.366728   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-b62sg/test-cluster-bt9dg"
I0729 09:31:01.371157   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xsl8s" "namespace"="test-mhc-b62sg" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0729 09:31:01.408969   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
inframachine created: test-mhc-machine-infra-pk2lw
I0729 09:31:01.429851   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-jdxmx
I0729 09:31:01.459457   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
I0729 09:31:01.459764   10526 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-qfdh5/test-mhc-r5xcv/test-mhc-machine-jdxmx/"
E0729 09:31:01.537008   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zxzx9, got []"  "node"="test-mhc-node-zxzx9"
E0729 09:31:01.537279   10526 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-zxzx9"
node created: test-mhc-node-zxzx9
I0729 09:31:01.538098   10526 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5" "noderef"="test-mhc-node-zxzx9"
E0729 09:31:01.550151   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zxzx9, got []"  "node"="test-mhc-node-zxzx9"
E0729 09:31:01.550173   10526 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-zxzx9"
E0729 09:31:01.550204   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zxzx9, got []"  "node"="test-mhc-node-zxzx9"
E0729 09:31:01.550205   10526 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-zxzx9"
inframachine created: test-mhc-machine-infra-tm98b
machine created: test-mhc-machine-kr2d5
I0729 09:31:01.670802   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
I0729 09:31:01.671285   10526 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-qfdh5/test-mhc-r5xcv/test-mhc-machine-kr2d5/"
node created: test-mhc-node-8tglz
E0729 09:31:01.720517   10526 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-8tglz"
E0729 09:31:01.720673   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8tglz, got []"  "node"="test-mhc-node-8tglz"
I0729 09:31:01.730289   10526 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5" "noderef"="test-mhc-node-8tglz"
I0729 09:31:01.875931   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
I0729 09:31:01.905758   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
Cleaning up nodes, machines and infra machines.
I0729 09:31:01.922949   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
I0729 09:31:01.923587   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qfdh5/test-mhc-r5xcv/test-mhc-machine-jdxmx/"
I0729 09:31:01.970657   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
E0729 09:31:01.971140   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:01.971177   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qfdh5/test-mhc-r5xcv/test-mhc-machine-jdxmx/"
I0729 09:31:01.971616   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qfdh5/test-mhc-r5xcv/test-mhc-machine-kr2d5/"
E0729 09:31:01.984408   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qfdh5/test-cluster-pghwv"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0729 09:31:01.991424   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-r5xcv\" not found" "controller"="machinehealthcheck" "name"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5"
inframachine created: test-mhc-machine-infra-9t9ts
machine created: test-mhc-machine-jspd2
E0729 09:31:02.273192   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-bc5bb/machine-reconcile-t78t6"
E0729 09:31:02.971545   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:02.991729   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r5xcv" "namespace"="test-mhc-qfdh5" 
I0729 09:31:02.991838   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.005972   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 09:31:03.126280   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.127378   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.129257   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 339 lines ...
I0729 09:31:03.961665   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.963533   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.965230   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.966943   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.968652   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.970487   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
E0729 09:31:03.971889   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:03.972163   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.973869   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.975562   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.977244   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.979380   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:03.981054   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 459 lines ...
I0729 09:31:04.979299   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:04.981110   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:04.983068   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:04.983711   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:04.984841   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:04.986870   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
E0729 09:31:04.987839   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:04.987896   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:04.988119   10526 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-dh4qq/test-mhc-dxdhf/test-mhc-machine-jspd2/"
I0729 09:31:05.017620   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.018051   10526 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-dh4qq/test-mhc-dxdhf/test-mhc-machine-jspd2/"
E0729 09:31:05.061618   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2qpg7, got []"  "node"="test-mhc-node-2qpg7"
node created: test-mhc-node-2qpg7
I0729 09:31:05.069515   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
inframachine created: test-mhc-machine-infra-d7r85
machine created: test-mhc-machine-n24wj
I0729 09:31:05.089701   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.104668   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 342 lines ...
I0729 09:31:05.965882   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.970133   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.972345   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.981894   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.984158   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.986320   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
E0729 09:31:05.988146   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:05.988446   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.990536   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.992640   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.994712   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.996765   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:05.998821   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 350 lines ...
I0729 09:31:07.014057   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.016221   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.018358   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.020542   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.022689   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.033766   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
E0729 09:31:07.041543   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:07.044845   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.046106   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.047928   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.049120   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.050380   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:07.051957   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 357 lines ...
I0729 09:31:08.043549   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.046037   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.048385   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.050614   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.051624   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.053770   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
E0729 09:31:08.055641   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:08.056101   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.056484   10526 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-dh4qq/test-mhc-dxdhf/test-mhc-machine-n24wj/"
I0729 09:31:08.070115   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.070600   10526 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-dh4qq/test-mhc-dxdhf/test-mhc-machine-n24wj/"
E0729 09:31:08.107840   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4pzqc, got []"  "node"="test-mhc-node-4pzqc"
node created: test-mhc-node-4pzqc
inframachine created: test-mhc-machine-infra-lkvdk
I0729 09:31:08.118303   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
machine created: test-mhc-machine-7slk9
I0729 09:31:08.137852   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:08.144966   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 273 lines ...
I0729 09:31:09.050248   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.056731   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.059354   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.061953   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.064499   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.067357   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
E0729 09:31:09.067648   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:09.068950   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.070542   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.072046   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.075414   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.077292   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:09.082686   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 304 lines ...
I0729 09:31:10.100843   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.102855   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.109000   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.113163   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.119504   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.124857   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
E0729 09:31:10.127208   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:10.127292   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.128694   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.131826   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.134056   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.136339   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:10.139161   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
... skipping 275 lines ...
I0729 09:31:11.138746   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.140224   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.142551   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.143970   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.146151   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.148187   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.148679   10526 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-dh4qq/test-mhc-dxdhf/test-mhc-machine-7slk9/"
E0729 09:31:11.152569   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:11.165425   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.175507   10526 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-dh4qq/test-mhc-dxdhf/test-mhc-machine-7slk9/"
E0729 09:31:11.183498   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pmsfl, got []"  "node"="test-mhc-node-pmsfl"
node created: test-mhc-node-pmsfl
Cleaning up nodes, machines and infra machines.
I0729 09:31:11.193867   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.194447   10526 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-dh4qq/test-mhc-dxdhf/test-mhc-machine-7slk9/test-mhc-node-pmsfl"
Cleaning up nodes, machines and infra machines.
I0729 09:31:11.211692   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.212267   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dh4qq/test-mhc-dxdhf/test-mhc-machine-7slk9/"
I0729 09:31:11.228755   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:11.229354   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dh4qq/test-mhc-dxdhf/test-mhc-machine-7slk9/"
I0729 09:31:11.229670   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dh4qq/test-mhc-dxdhf/test-mhc-machine-jspd2/"
I0729 09:31:11.256187   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6fsrv" "namespace"="test-mhc-dh4qq" "count"=2
I0729 09:31:11.256283   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6fsrv" "namespace"="test-mhc-dh4qq" "descendants"="Worker machines: test-mhc-machine-jspd2,test-mhc-machine-n24wj,test-mhc-machine-7slk9" "indirect descendants count"=1
I0729 09:31:11.261790   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6fsrv" "namespace"="test-mhc-dh4qq" "count"=2
I0729 09:31:11.261869   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6fsrv" "namespace"="test-mhc-dh4qq" "descendants"="Worker machines: test-mhc-machine-jspd2,test-mhc-machine-n24wj,test-mhc-machine-7slk9" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
inframachine created: test-mhc-machine-infra-5rxkw
machine created: test-mhc-machine-pqcb9
I0729 09:31:11.405233   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-dh4qq/test-mhc-dxdhf/test-mhc-machine-n24wj/"
E0729 09:31:11.422395   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-dxdhf\" not found" "controller"="machinehealthcheck" "name"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq"
I0729 09:31:12.153116   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6fsrv" "machine"="test-mhc-machine-n24wj" "namespace"="test-mhc-dh4qq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4pzqc"}
E0729 09:31:12.201794   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-n24wj\" not found" "controller"="machine" "name"="test-mhc-machine-n24wj" "namespace"="test-mhc-dh4qq"
I0729 09:31:12.422686   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:12.460244   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 09:31:12.489409   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxdhf" "namespace"="test-mhc-dh4qq" 
I0729 09:31:12.489485   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:12.497196   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:12.507446   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:12.548323   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:12.629276   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:12.790339   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:13.111328   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:13.202223   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:13.752427   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:14.202759   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6fsrv" "machine"="test-mhc-machine-7slk9" "namespace"="test-mhc-dh4qq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pmsfl"}
E0729 09:31:14.255756   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7slk9\" not found" "controller"="machine" "name"="test-mhc-machine-7slk9" "namespace"="test-mhc-dh4qq"
I0729 09:31:15.037704   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:15.256330   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6fsrv" "machine"="test-mhc-machine-jspd2" "namespace"="test-mhc-dh4qq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2qpg7"}
E0729 09:31:15.317605   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jspd2\" not found" "controller"="machine" "name"="test-mhc-machine-jspd2" "namespace"="test-mhc-dh4qq"
E0729 09:31:16.273060   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-dh4qq/test-cluster-6fsrv"
E0729 09:31:16.317961   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:17.325975   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:17.332526   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:17.332918   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:17.349325   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:17.423976   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bvmv5, got []"  "node"="test-mhc-node-bvmv5"
node created: test-mhc-node-bvmv5
I0729 09:31:17.432787   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
inframachine created: test-mhc-machine-infra-w55wc
I0729 09:31:17.458454   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
machine created: test-mhc-machine-9sssn
I0729 09:31:17.471853   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:17.477097   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:17.502068   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:17.543483   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:17.624782   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:17.786300   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:18.107942   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:18.333016   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:18.749308   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.347202   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.364084   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.376574   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.384690   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.398578   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.401953   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:19.403714   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:19.420686   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:19.468203   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kr42j, got []"  "node"="test-mhc-node-kr42j"
node created: test-mhc-node-kr42j
I0729 09:31:19.475846   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
inframachine created: test-mhc-machine-infra-spczf
I0729 09:31:19.487961   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.493958   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
machine created: test-mhc-machine-fp2gk
I0729 09:31:19.507699   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:19.513579   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:20.030646   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:20.404167   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:21.415148   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.428481   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.437143   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.452678   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.461426   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.468394   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:21.472417   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:21.473031   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.495237   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
E0729 09:31:21.509828   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jhbvk, got []"  "node"="test-mhc-node-jhbvk"
node created: test-mhc-node-jhbvk
Cleaning up nodes, machines and infra machines.
I0729 09:31:21.516089   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.530063   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
Cleaning up nodes, machines and infra machines.
I0729 09:31:21.571837   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9p4rl" "namespace"="test-mhc-q8gkv" "count"=2
... skipping 4 lines ...
inframachine created: test-mhc-machine-infra-c9sw9
machine created: test-mhc-machine-5q8qd
I0729 09:31:21.766303   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:21.809776   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 09:31:21.928711   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbcz6" "namespace"="test-mhc-q8gkv" 
I0729 09:31:21.928787   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
E0729 09:31:22.472782   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:23.473319   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9p4rl" "machine"="test-mhc-machine-pqcb9" "namespace"="test-mhc-q8gkv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-bvmv5"}
E0729 09:31:23.519955   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-pqcb9\" not found" "controller"="machine" "name"="test-mhc-machine-pqcb9" "namespace"="test-mhc-q8gkv"
I0729 09:31:24.520553   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9p4rl" "machine"="test-mhc-machine-9sssn" "namespace"="test-mhc-q8gkv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-kr42j"}
E0729 09:31:24.581798   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9sssn\" not found" "controller"="machine" "name"="test-mhc-machine-9sssn" "namespace"="test-mhc-q8gkv"
I0729 09:31:25.582475   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9p4rl" "machine"="test-mhc-machine-fp2gk" "namespace"="test-mhc-q8gkv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jhbvk"}
E0729 09:31:25.630087   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fp2gk\" not found" "controller"="machine" "name"="test-mhc-machine-fp2gk" "namespace"="test-mhc-q8gkv"
E0729 09:31:26.590561   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-q8gkv/test-cluster-9p4rl"
I0729 09:31:26.642879   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
E0729 09:31:26.650299   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:26.650565   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
node created: test-mhc-node-v7t9x
E0729 09:31:26.661359   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v7t9x, got []"  "node"="test-mhc-node-v7t9x"
I0729 09:31:26.669309   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
inframachine created: test-mhc-machine-infra-r4dlx
I0729 09:31:26.689604   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:26.694873   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
machine created: test-mhc-machine-5c2p8
I0729 09:31:26.704496   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:26.714817   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
E0729 09:31:27.651026   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:28.668681   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.675705   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.696300   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.703576   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.711911   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.721414   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
node created: test-mhc-node-cj9hs
E0729 09:31:28.730521   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cj9hs, got []"  "node"="test-mhc-node-cj9hs"
I0729 09:31:28.738207   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
inframachine created: test-mhc-machine-infra-hl762
machine created: test-mhc-machine-5wzvt
I0729 09:31:28.771068   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.785983   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.795577   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
... skipping 7 lines ...
Cleaning up nodes, machines and infra machines.
I0729 09:31:28.973399   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
Cleaning up nodes, machines and infra machines.
I0729 09:31:28.982814   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jcrjp" "machine"="test-mhc-machine-5wzvt" "namespace"="test-mhc-4l9gr" "cause"="noderef is nil" "node"=null
I0729 09:31:28.987839   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.990494   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:28.991105   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4l9gr/test-mhc-b99nn/test-mhc-machine-5q8qd/"
I0729 09:31:29.026411   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:29.027110   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4l9gr/test-mhc-b99nn/test-mhc-machine-5q8qd/"
I0729 09:31:29.027599   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4l9gr/test-mhc-b99nn/test-mhc-machine-5c2p8/"
I0729 09:31:29.052214   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jcrjp" "namespace"="test-mhc-4l9gr" "count"=3
I0729 09:31:29.052304   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jcrjp" "namespace"="test-mhc-4l9gr" "descendants"="Worker machines: test-mhc-machine-5wzvt,test-mhc-machine-5q8qd,test-mhc-machine-5c2p8" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
I0729 09:31:29.059883   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jcrjp" "namespace"="test-mhc-4l9gr" "count"=3
I0729 09:31:29.059946   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jcrjp" "namespace"="test-mhc-4l9gr" "descendants"="Worker machines: test-mhc-machine-5q8qd,test-mhc-machine-5c2p8,test-mhc-machine-5wzvt" "indirect descendants count"=0
inframachine created: test-mhc-machine-infra-xs52j
machine created: test-mhc-machine-9bp5h
E0729 09:31:29.182988   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-b99nn\" not found" "controller"="machinehealthcheck" "name"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr"
E0729 09:31:29.200123   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5wzvt\" not found" "controller"="machine" "name"="test-mhc-machine-5wzvt" "namespace"="test-mhc-4l9gr"
I0729 09:31:30.183281   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:30.195372   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 09:31:30.200616   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jcrjp" "machine"="test-mhc-machine-5q8qd" "namespace"="test-mhc-4l9gr" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-v7t9x"}
E0729 09:31:30.246310   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5q8qd\" not found" "controller"="machine" "name"="test-mhc-machine-5q8qd" "namespace"="test-mhc-4l9gr"
I0729 09:31:30.323237   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b99nn" "namespace"="test-mhc-4l9gr" 
I0729 09:31:30.323321   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:30.324440   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:30.326128   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:30.328100   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:30.330434   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
... skipping 421 lines ...
I0729 09:31:31.287976   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.292243   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.294072   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.296122   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.298052   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.300277   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
E0729 09:31:31.301157   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5c2p8\" not found" "controller"="machine" "name"="test-mhc-machine-5c2p8" "namespace"="test-mhc-4l9gr"
I0729 09:31:31.303161   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.305205   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.307003   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.308757   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.310800   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:31.312787   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
... skipping 437 lines ...
I0729 09:31:32.279982   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.281794   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.289575   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.295393   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.297802   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.303631   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
E0729 09:31:32.318384   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:32.319119   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.319443   10526 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-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/"
I0729 09:31:32.332396   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.333023   10526 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-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/"
E0729 09:31:32.406182   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n65bt, got []"  "node"="test-mhc-node-n65bt"
node created: test-mhc-node-n65bt
E0729 09:31:32.406845   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n65bt, got []"  "node"="test-mhc-node-n65bt"
I0729 09:31:32.416248   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.433342   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.450625   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.454465   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.455934   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.456499   10526 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-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/test-mhc-node-n65bt"
I0729 09:31:32.474932   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.475312   10526 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-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/test-mhc-node-n65bt"
Cleaning up nodes, machines and infra machines.
I0729 09:31:32.481988   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.482424   10526 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-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/test-mhc-node-n65bt"
I0729 09:31:32.485545   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.485964   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/"
I0729 09:31:32.496745   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.497072   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/"
I0729 09:31:32.500275   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.500814   10526 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7ckl7/test-mhc-8hnfk/test-mhc-machine-9bp5h/"
I0729 09:31:32.512979   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2bnc5" "namespace"="test-mhc-7ckl7" "descendants"="Worker machines: test-mhc-machine-9bp5h" "indirect descendants count"=1
I0729 09:31:32.518959   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2bnc5" "namespace"="test-mhc-7ckl7" "descendants"="Worker machines: test-mhc-machine-9bp5h" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0729 09:31:32.524702   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8hnfk" "namespace"="test-mhc-7ckl7" 
I0729 09:31:32.732756   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-xx8x8" "namespace"="test-mhc-xgbfk" "creating"=1 "need"=1
I0729 09:31:32.732823   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-xx8x8" "namespace"="test-mhc-xgbfk" 
I0729 09:31:32.747384   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-xx8x8-dg92w\"" "machineset"="mhc-ms-xx8x8" "namespace"="test-mhc-xgbfk" 
I0729 09:31:32.818268   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:32.842331   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0729 09:31:32.861277   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
E0729 09:31:33.318873   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:33.864303   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
E0729 09:31:34.080710   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4l9gr/test-cluster-jcrjp"
I0729 09:31:34.319362   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2bnc5" "machine"="test-mhc-machine-9bp5h" "namespace"="test-mhc-7ckl7" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-n65bt"}
E0729 09:31:34.382344   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9bp5h\" not found" "controller"="machine" "name"="test-mhc-machine-9bp5h" "namespace"="test-mhc-7ckl7"
I0729 09:31:34.865328   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:35.394466   10526 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-xx8x8" "namespace"="test-mhc-xgbfk" 
I0729 09:31:35.394652   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:35.395991   10526 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-xx8x8" "namespace"="test-mhc-xgbfk" 
I0729 09:31:35.396107   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:35.407172   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
... skipping 5 lines ...
I0729 09:31:35.429167   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
I0729 09:31:35.429215   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
I0729 09:31:35.869808   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:36.427146   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
I0729 09:31:36.427196   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.000630   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.001117   10526 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-xgbfk/test-mhc-2v6t2/mhc-ms-xx8x8-dg92w/"
I0729 09:31:37.009459   10526 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-xx8x8" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.052354   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.052705   10526 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-xgbfk/test-mhc-2v6t2/mhc-ms-xx8x8-dg92w/"
I0729 09:31:37.053936   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.053979   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.069461   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.069852   10526 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-xgbfk/test-mhc-2v6t2/mhc-ms-xx8x8-dg92w/"
I0729 09:31:37.077286   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4j2g8" "namespace"="test-mhc-xgbfk" "count"=1
I0729 09:31:37.077350   10526 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-4j2g8" "namespace"="test-mhc-xgbfk" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-xx8x8"
I0729 09:31:37.078236   10526 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-xx8x8" "namespace"="test-mhc-xgbfk" "machine"="mhc-ms-xx8x8-dg92w"
I0729 09:31:37.082064   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2v6t2" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.082603   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
I0729 09:31:37.082638   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" 
... skipping 4 lines ...
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0729 09:31:37.182068   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
inframachine created: test-mhc-machine-infra-rvmnm
I0729 09:31:37.206141   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-8dgmk
I0729 09:31:37.306499   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4j2g8" "machine"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk" "cause"="cluster is being deleted" "node"=null
E0729 09:31:37.317973   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mxwhx, got []"  "node"="test-mhc-node-mxwhx"
E0729 09:31:37.318245   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mxwhx, got []"  "node"="test-mhc-node-mxwhx"
node created: test-mhc-node-mxwhx
E0729 09:31:37.320702   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mxwhx, got []"  "node"="test-mhc-node-mxwhx"
E0729 09:31:37.340101   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-xx8x8-dg92w\" not found" "controller"="machine" "name"="mhc-ms-xx8x8-dg92w" "namespace"="test-mhc-xgbfk"
I0729 09:31:37.371370   10526 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-8dgmk" "target"="test-mhc-7tb6s/test-mhc-25xpv/test-mhc-machine-8dgmk/"
I0729 09:31:37.409224   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
I0729 09:31:37.433160   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
I0729 09:31:37.440408   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
I0729 09:31:37.449873   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
I0729 09:31:37.454479   10526 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-8dgmk" "target"="test-mhc-7tb6s/test-mhc-25xpv/test-mhc-machine-8dgmk/test-mhc-node-mxwhx"
I0729 09:31:37.478287   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
Cleaning up nodes, machines and infra machines.
I0729 09:31:37.494588   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
I0729 09:31:37.507869   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
I0729 09:31:37.522848   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-25xpv" "namespace"="test-mhc-7tb6s" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0729 09:31:37.536041   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fszdg" "namespace"="test-mhc-7tb6s" "descendants"="Worker machines: test-mhc-machine-8dgmk" "indirect descendants count"=1
E0729 09:31:37.538761   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7ckl7/test-cluster-2bnc5"
I0729 09:31:37.553696   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fszdg" "namespace"="test-mhc-7tb6s" "descendants"="Worker machines: test-mhc-machine-8dgmk" "indirect descendants count"=1
I0729 09:31:37.556922   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
inframachine created: test-mhc-machine-infra-tz986
I0729 09:31:37.576194   10526 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-c58v8
I0729 09:31:37.699594   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
... skipping 310 lines ...
I0729 09:31:38.388026   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.389846   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.392298   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.394231   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.395955   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.397729   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
E0729 09:31:38.399075   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8dgmk\" not found" "controller"="machine" "name"="test-mhc-machine-8dgmk" "namespace"="test-mhc-7tb6s"
I0729 09:31:38.399494   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.401280   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.403385   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.405211   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.407191   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:38.408978   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
... skipping 467 lines ...
I0729 09:31:39.389303   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.391004   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.392667   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.394501   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.396352   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.398036   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
E0729 09:31:39.399462   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
I0729 09:31:39.399679   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.401465   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.403395   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.405172   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.406986   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:39.408674   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
... skipping 453 lines ...
I0729 09:31:40.405246   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.407259   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.407947   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.409148   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.410977   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.412783   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
E0729 09:31:40.413071   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
I0729 09:31:40.416854   10526 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-c58v8" "target"="test-mhc-2jjnf/test-mhc-cpxst/test-mhc-machine-c58v8/"
I0729 09:31:40.436644   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
E0729 09:31:40.509593   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ggm87, got []"  "node"="test-mhc-node-ggm87"
E0729 09:31:40.509684   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ggm87, got []"  "node"="test-mhc-node-ggm87"
node created: test-mhc-node-ggm87
E0729 09:31:40.510321   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ggm87, got []"  "node"="test-mhc-node-ggm87"
I0729 09:31:40.529846   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.555767   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.565958   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.570478   10526 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-c58v8" "target"="test-mhc-2jjnf/test-mhc-cpxst/test-mhc-machine-c58v8/test-mhc-node-ggm87"
I0729 09:31:40.592862   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.596236   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.601127   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.646468   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
Cleaning up nodes, machines and infra machines.
I0729 09:31:40.659261   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
I0729 09:31:40.666251   10526 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-c58v8" "target"="test-mhc-2jjnf/test-mhc-cpxst/test-mhc-machine-c58v8/"
I0729 09:31:40.679536   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-r7nsj" "namespace"="test-mhc-2jjnf" "descendants"="Worker machines: test-mhc-machine-c58v8" "indirect descendants count"=1
I0729 09:31:40.691441   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-r7nsj" "namespace"="test-mhc-2jjnf" "descendants"="Worker machines: test-mhc-machine-c58v8" "indirect descendants count"=1
E0729 09:31:40.691742   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-cpxst\" not found" "controller"="machinehealthcheck" "name"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf"
--- PASS: TestMachineHealthCheck_Reconcile (40.77s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.07s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.07s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.14s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.43s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.17s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0729 09:31:40.695148   10526 machinehealthcheck_controller.go:416]  "msg"="expected a Cluster" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace
--- PASS: TestClusterToMachineHealthCheck (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace (0.00s)
=== RUN   TestMachineToMachineHealthCheck
=== RUN   TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine
E0729 09:31:40.696626   10526 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
E0729 09:31:40.698448   10526 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0729 09:31:40.698725   10526 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got []"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_two_Machines_exist_for_the_Node
E0729 09:31:40.699170   10526 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0729 09:31:40.702742   10526 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0729 09:31:40.703472   10526 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0729 09:31:40.705377   10526 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0729 09:31:40.717355   10526 machineset_controller.go:151]  "msg"="Failed to reconcile MachineSet" "error"="failed to calculate MachineSet's Status: failed to calculate status for MachineSet default/machineset1: invalid label key \"--$-invalid\": name part must consist of alphanumeric characters, '-', '_' or '.', and must start and end with an alphanumeric character (e.g. 'MyName',  or 'my.name',  or '123-abc', regex used for validation is '([A-Za-z0-9][-A-Za-z0-9_.]*)?[A-Za-z0-9]')" "machineset"="machineset1" "namespace"="default" 
--- PASS: TestMachineSetReconcile (0.00s)
    --- PASS: TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion (0.00s)
    --- PASS: TestMachineSetReconcile/records_event_if_reconcile_fails (0.00s)
=== RUN   TestMachineSetToMachines
=== RUN   TestMachineSetToMachines/should_return_empty_request_when_controller_is_set
=== RUN   TestMachineSetToMachines/should_return_nil_if_machine_has_no_owner_reference
... skipping 8 lines ...
--- PASS: TestAdoptOrphan (0.00s)
=== RUN   TestHasMatchingLabels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_has_empty_selector
=== RUN   TestHasMatchingLabels/machine_set_has_bad_selector
E0729 09:31:40.729855   10526 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 65 lines ...
I0729 09:31:40.910068   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-vngfw-qxh5x\"" "machineset"="ms-vngfw" "namespace"="ms-test" 
I0729 09:31:40.910129   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-vngfw" "namespace"="ms-test" 
I0729 09:31:40.926168   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-vngfw-8nlqf\"" "machineset"="ms-vngfw" "namespace"="ms-test" 
I0729 09:31:41.045144   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-vngfw" "namespace"="ms-test" "creating"=1 "need"=2
I0729 09:31:41.045197   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-vngfw" "namespace"="ms-test" 
I0729 09:31:41.061995   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-vngfw-kdbp5\"" "machineset"="ms-vngfw" "namespace"="ms-test" 
E0729 09:31:41.138941   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.139027   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.139186   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.242983   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.243048   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.243227   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.243240   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.243257   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.243279   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-8nlqf-s52cz, got []"  "node"="ms-vngfw-8nlqf-s52cz"
E0729 09:31:41.274989   10526 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-vngfw-8nlqf-s52cz for machine ms-test/ms-vngfw-8nlqf: the cache is not started, can not read objects" "machineset"="ms-vngfw" "namespace"="ms-test" 
E0729 09:31:41.280926   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.280999   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.280999   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.285734   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.285825   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.285833   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.285882   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.287441   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
E0729 09:31:41.287568   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vngfw-kdbp5-tl7rz, got []"  "node"="ms-vngfw-kdbp5-tl7rz"
I0729 09:31:41.409626   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vngfw-kdbp5,ms-vngfw-8nlqf" "indirect descendants count"=2
I0729 09:31:41.413792   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-r7nsj" "machine"="test-mhc-machine-c58v8" "namespace"="test-mhc-2jjnf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ggm87"}
I0729 09:31:41.413911   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vngfw-kdbp5,ms-vngfw-8nlqf" "indirect descendants count"=2
•E0729 09:31:41.476231   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-c58v8\" not found" "controller"="machine" "name"="test-mhc-machine-c58v8" "namespace"="test-mhc-2jjnf"
I0729 09:31:41.523605   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0729 09:31:41.523662   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" 
I0729 09:31:41.553974   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-d5cr2-6657c7fddb-vmxpv\"" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" 
I0729 09:31:41.554045   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" 
I0729 09:31:41.565591   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-d5cr2-6657c7fddb-4j25t\"" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" 
I0729 09:31:41.692025   10526 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpxst" "namespace"="test-mhc-2jjnf" 
... skipping 5 lines ...
I0729 09:31:41.815527   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0729 09:31:41.815582   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" 
I0729 09:31:41.830191   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-d5cr2-6657c7fddb-ld45t\"" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" 
I0729 09:31:41.917779   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0729 09:31:41.917828   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" 
I0729 09:31:41.929198   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-d5cr2-cdfc6fd6c-nc5fb\"" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" 
E0729 09:31:42.017595   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg, got []"  "node"="md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"
E0729 09:31:42.017795   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg, got []"  "node"="md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"
E0729 09:31:42.017811   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg, got []"  "node"="md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"
E0729 09:31:42.104177   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xgbfk/test-cluster-4j2g8"
E0729 09:31:42.121132   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg, got []"  "node"="md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"
E0729 09:31:42.121185   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg, got []"  "node"="md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"
E0729 09:31:42.121524   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg, got []"  "node"="md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"
E0729 09:31:42.121594   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg, got []"  "node"="md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"
E0729 09:31:42.150679   10526 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-d5cr2-cdfc6fd6c-nc5fb-m8rwg for machine md-test/md-d5cr2-cdfc6fd6c-nc5fb: the cache is not started, can not read objects" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" 
I0729 09:31:42.176956   10526 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0729 09:31:42.177006   10526 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0729 09:31:42.182629   10526 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "machine"="md-d5cr2-6657c7fddb-rgmrd"
I0729 09:31:42.203189   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0729 09:31:42.203243   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" 
I0729 09:31:42.219551   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-d5cr2-cdfc6fd6c-55rrg\"" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" 
E0729 09:31:42.249851   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-55rrg-mxq2s, got []"  "node"="md-d5cr2-cdfc6fd6c-55rrg-mxq2s"
E0729 09:31:42.250113   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-55rrg-mxq2s, got []"  "node"="md-d5cr2-cdfc6fd6c-55rrg-mxq2s"
E0729 09:31:42.254326   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-55rrg-mxq2s, got []"  "node"="md-d5cr2-cdfc6fd6c-55rrg-mxq2s"
E0729 09:31:42.254360   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-55rrg-mxq2s, got []"  "node"="md-d5cr2-cdfc6fd6c-55rrg-mxq2s"
E0729 09:31:42.254378   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-55rrg-mxq2s, got []"  "node"="md-d5cr2-cdfc6fd6c-55rrg-mxq2s"
E0729 09:31:42.254396   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-55rrg-mxq2s, got []"  "node"="md-d5cr2-cdfc6fd6c-55rrg-mxq2s"
I0729 09:31:42.296722   10526 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0729 09:31:42.296768   10526 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0729 09:31:42.301808   10526 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "machine"="md-d5cr2-6657c7fddb-m87zw"
I0729 09:31:42.411945   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0729 09:31:42.411988   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" 
I0729 09:31:42.422871   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-d5cr2-cdfc6fd6c-snhq9\"" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" 
E0729 09:31:42.539340   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-snhq9-bg9sz, got []"  "node"="md-d5cr2-cdfc6fd6c-snhq9-bg9sz"
E0729 09:31:42.539678   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-snhq9-bg9sz, got []"  "node"="md-d5cr2-cdfc6fd6c-snhq9-bg9sz"
E0729 09:31:42.554361   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7tb6s/test-cluster-fszdg"
E0729 09:31:42.643681   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-snhq9-bg9sz, got []"  "node"="md-d5cr2-cdfc6fd6c-snhq9-bg9sz"
E0729 09:31:42.643762   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-cdfc6fd6c-snhq9-bg9sz, got []"  "node"="md-d5cr2-cdfc6fd6c-snhq9-bg9sz"
I0729 09:31:42.717126   10526 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0729 09:31:42.717171   10526 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0729 09:31:42.721886   10526 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-d5cr2-6657c7fddb" "namespace"="md-test" "machine"="md-d5cr2-6657c7fddb-ld45t"
I0729 09:31:42.734329   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:42.734378   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:42.755238   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:42.755281   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:42.767444   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-d5cr2-6657c7fddb-ld45t" "namespace"="md-test" "cause"="noderef is nil" "node"=null
E0729 09:31:42.849065   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-nc5fb\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-nc5fb" "namespace"="md-test"
I0729 09:31:42.992593   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0729 09:31:42.992650   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" 
I0729 09:31:43.004852   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-d5cr2-74d45c49c5-k4hfg\"" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" 
E0729 09:31:43.091269   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-k4hfg-mnmwt, got []"  "node"="md-d5cr2-74d45c49c5-k4hfg-mnmwt"
E0729 09:31:43.194628   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-k4hfg-mnmwt, got []"  "node"="md-d5cr2-74d45c49c5-k4hfg-mnmwt"
E0729 09:31:43.194755   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-k4hfg-mnmwt, got []"  "node"="md-d5cr2-74d45c49c5-k4hfg-mnmwt"
I0729 09:31:43.230221   10526 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0729 09:31:43.230262   10526 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0729 09:31:43.233988   10526 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "machine"="md-d5cr2-cdfc6fd6c-55rrg"
I0729 09:31:43.344538   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0729 09:31:43.344597   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" 
I0729 09:31:43.356673   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-d5cr2-74d45c49c5-b6ktd\"" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" 
E0729 09:31:43.438147   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-b6ktd-2pw69, got []"  "node"="md-d5cr2-74d45c49c5-b6ktd-2pw69"
E0729 09:31:43.541395   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-b6ktd-2pw69, got []"  "node"="md-d5cr2-74d45c49c5-b6ktd-2pw69"
E0729 09:31:43.541457   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-b6ktd-2pw69, got []"  "node"="md-d5cr2-74d45c49c5-b6ktd-2pw69"
I0729 09:31:43.581999   10526 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0729 09:31:43.582050   10526 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0729 09:31:43.586543   10526 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-d5cr2-cdfc6fd6c" "namespace"="md-test" "machine"="md-d5cr2-cdfc6fd6c-nc5fb"
I0729 09:31:43.697372   10526 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0729 09:31:43.697443   10526 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" 
I0729 09:31:43.708630   10526 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-d5cr2-74d45c49c5-95ssd\"" "machineset"="md-d5cr2-74d45c49c5" "namespace"="md-test" 
E0729 09:31:43.803417   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-95ssd-gfmnl, got []"  "node"="md-d5cr2-74d45c49c5-95ssd-gfmnl"
I0729 09:31:43.849773   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-d5cr2-cdfc6fd6c-55rrg" "namespace"="md-test" "cause"="no control plane members" "node"={"name":"md-d5cr2-cdfc6fd6c-55rrg-mxq2s"}
E0729 09:31:43.910002   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-95ssd-gfmnl, got []"  "node"="md-d5cr2-74d45c49c5-95ssd-gfmnl"
E0729 09:31:43.910055   10526 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-d5cr2-74d45c49c5-95ssd-gfmnl, got []"  "node"="md-d5cr2-74d45c49c5-95ssd-gfmnl"
E0729 09:31:43.911219   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-snhq9\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-snhq9" "namespace"="md-test"
E0729 09:31:43.928991   10526 machinedeployment_controller.go:149] controllers/MachineDeployment "msg"="Failed to reconcile MachineDeployment" "error"="MachineDeployment.cluster.x-k8s.io \"md-d5cr2\" not found" "machinedeployment"="md-d5cr2" "namespace"="md-test" 
E0729 09:31:43.929558   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="MachineDeployment.cluster.x-k8s.io \"md-d5cr2\" not found" "controller"="machinedeployment" "name"="md-d5cr2" "namespace"="md-test"
I0729 09:31:43.930436   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-d5cr2-74d45c49c5,md-d5cr2-cdfc6fd6c;Worker machines: md-d5cr2-6657c7fddb-4j25t,md-d5cr2-cdfc6fd6c-55rrg,md-d5cr2-74d45c49c5-b6ktd,md-d5cr2-74d45c49c5-95ssd,md-d5cr2-6657c7fddb-vmxpv,md-d5cr2-cdfc6fd6c-snhq9,md-d5cr2-6657c7fddb-ld45t,md-d5cr2-cdfc6fd6c-nc5fb,md-d5cr2-74d45c49c5-k4hfg" "indirect descendants count"=11
•I0729 09:31:43.934081   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0729 09:31:43.934396   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-d5cr2-74d45c49c5,md-d5cr2-cdfc6fd6c;Worker machines: md-d5cr2-6657c7fddb-ld45t,md-d5cr2-cdfc6fd6c-nc5fb,md-d5cr2-74d45c49c5-k4hfg,md-d5cr2-6657c7fddb-vmxpv,md-d5cr2-cdfc6fd6c-snhq9,md-d5cr2-74d45c49c5-b6ktd,md-d5cr2-74d45c49c5-95ssd,md-d5cr2-6657c7fddb-4j25t,md-d5cr2-cdfc6fd6c-55rrg" "indirect descendants count"=11
I0729 09:31:43.935015   10526 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0729 09:31:43.935076   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0729 09:31:43.935783   10526 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
... skipping 15 lines ...
I0729 09:31:43.945102   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
•I0729 09:31:43.946776   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0729 09:31:43.947527   10526 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0729 09:31:43.948243   10526 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0729 09:31:43.948274   10526 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0729 09:31:43.948883   10526 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0729 09:31:43.950302   10526 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" 
••E0729 09:31:44.079365   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-qmnbh\" not found" "controller"="cluster" "name"="test1-qmnbh" "namespace"="default"
I0729 09:31:44.933706   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:44.933747   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:44.938182   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:44.938225   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:44.938915   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-d5cr2-6657c7fddb-ld45t" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0729 09:31:44.965959   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-d5cr2-6657c7fddb-ld45t\" not found" "controller"="machine" "name"="md-d5cr2-6657c7fddb-ld45t" "namespace"="md-test"
•I0729 09:31:45.204418   10526 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-cgkbx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0729 09:31:45.319841   10526 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-cgkbx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0729 09:31:45.324247   10526 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-cgkbx" "namespace"="default"
I0729 09:31:45.966820   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-d5cr2-cdfc6fd6c-nc5fb" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"}
I0729 09:31:46.056791   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-d5cr2-cdfc6fd6c-55rrg" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-d5cr2-cdfc6fd6c-55rrg-mxq2s"}
E0729 09:31:46.086205   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-d5cr2-cdfc6fd6c-55rrg\" not found" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-55rrg" "namespace"="md-test"
E0729 09:31:46.337999   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
•E0729 09:31:47.090889   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-snhq9\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-snhq9" "namespace"="md-test"
E0729 09:31:47.349404   10526 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-2jjnf/test-cluster-r7nsj"
E0729 09:31:47.361514   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-mlpvj\" not found" "controller"="cluster" "name"="test3-mlpvj" "namespace"="default"
I0729 09:31:48.104309   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:48.104350   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:48.108619   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:48.108662   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:48.109326   10526 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-d5cr2-cdfc6fd6c-nc5fb" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-d5cr2-cdfc6fd6c-nc5fb-m8rwg"}
E0729 09:31:48.136206   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-d5cr2-cdfc6fd6c-nc5fb\" not found" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-nc5fb" "namespace"="md-test"
E0729 09:31:48.362354   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
E0729 09:31:49.168395   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-k4hfg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-k4hfg" "namespace"="md-test"
I0729 09:31:49.372351   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vngfw-kdbp5,ms-vngfw-8nlqf" "indirect descendants count"=2
E0729 09:31:49.372828   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
•E0729 09:31:50.194266   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-b6ktd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-b6ktd" "namespace"="md-test"
I0729 09:31:50.373519   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-d5cr2-74d45c49c5,md-d5cr2-cdfc6fd6c;Worker machines: md-d5cr2-6657c7fddb-vmxpv,md-d5cr2-cdfc6fd6c-snhq9,md-d5cr2-74d45c49c5-k4hfg,md-d5cr2-74d45c49c5-95ssd,md-d5cr2-6657c7fddb-4j25t,md-d5cr2-74d45c49c5-b6ktd" "indirect descendants count"=8
E0729 09:31:50.377782   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
E0729 09:31:51.223376   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-snhq9\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-snhq9" "namespace"="md-test"
E0729 09:31:51.378555   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
I0729 09:31:52.228129   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:52.228183   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:52.232341   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:52.232377   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
E0729 09:31:52.236421   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-k4hfg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-k4hfg" "namespace"="md-test"
E0729 09:31:52.388114   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
•E0729 09:31:53.236824   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-jdxmx\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-jdxmx" "namespace"="test-mhc-qfdh5"
E0729 09:31:53.388790   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
E0729 09:31:54.242047   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-b6ktd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-b6ktd" "namespace"="md-test"
E0729 09:31:54.389612   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
E0729 09:31:55.242436   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pghwv\" for machine \"test-mhc-machine-kr2d5\" in namespace \"test-mhc-qfdh5\": Cluster.cluster.x-k8s.io \"test-cluster-pghwv\" not found" "controller"="machine" "name"="test-mhc-machine-kr2d5" "namespace"="test-mhc-qfdh5"
E0729 09:31:55.399294   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
E0729 09:31:56.253604   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-snhq9\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-snhq9" "namespace"="md-test"
I0729 09:31:56.399858   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vngfw-kdbp5,ms-vngfw-8nlqf" "indirect descendants count"=2
E0729 09:31:56.400319   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
E0729 09:31:57.258555   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-k4hfg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-k4hfg" "namespace"="md-test"
I0729 09:31:57.400945   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-d5cr2-74d45c49c5,md-d5cr2-cdfc6fd6c;Worker machines: md-d5cr2-6657c7fddb-4j25t,md-d5cr2-74d45c49c5-b6ktd,md-d5cr2-74d45c49c5-95ssd,md-d5cr2-6657c7fddb-vmxpv,md-d5cr2-cdfc6fd6c-snhq9,md-d5cr2-74d45c49c5-k4hfg" "indirect descendants count"=8
E0729 09:31:57.401534   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
I0729 09:31:58.263168   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:58.263205   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:31:58.266597   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:31:58.266634   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
E0729 09:31:58.270171   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-b6ktd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-b6ktd" "namespace"="md-test"
E0729 09:31:58.402230   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
E0729 09:31:59.284751   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-snhq9\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-snhq9" "namespace"="md-test"
E0729 09:31:59.402992   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
E0729 09:32:00.289125   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-k4hfg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-k4hfg" "namespace"="md-test"
E0729 09:32:00.403698   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
E0729 09:32:01.294109   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-b6ktd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-b6ktd" "namespace"="md-test"
E0729 09:32:01.404418   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
I0729 09:32:02.299197   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:32:02.299239   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:32:02.303206   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:32:02.303242   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:32:02.316894   10526 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-nwkbp" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0729 09:32:02.328567   10526 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-nwkbp" "namespace"="default" 
E0729 09:32:02.344517   10526 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-nwkbp" "namespace"="default"
E0729 09:32:02.405141   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
E0729 09:32:03.349401   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-snhq9\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-snhq9" "namespace"="md-test"
I0729 09:32:03.405763   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vngfw-kdbp5,ms-vngfw-8nlqf" "indirect descendants count"=2
E0729 09:32:03.406395   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
E0729 09:32:04.354287   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-k4hfg\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-k4hfg" "namespace"="md-test"
I0729 09:32:04.407019   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-d5cr2-74d45c49c5,md-d5cr2-cdfc6fd6c;Worker machines: md-d5cr2-6657c7fddb-4j25t,md-d5cr2-74d45c49c5-b6ktd,md-d5cr2-74d45c49c5-95ssd,md-d5cr2-6657c7fddb-vmxpv,md-d5cr2-cdfc6fd6c-snhq9,md-d5cr2-74d45c49c5-k4hfg" "indirect descendants count"=8
E0729 09:32:04.407462   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
E0729 09:32:05.359817   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-74d45c49c5-b6ktd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-74d45c49c5-b6ktd" "namespace"="md-test"
E0729 09:32:05.408222   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-cgkbx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-cgkbx" "namespace"="default"
I0729 09:32:06.374489   10526 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-nwkbp" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0729 09:32:06.374729   10526 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-nwkbp" "namespace"="default" "noderef"="id-node-1"
E0729 09:32:06.388589   10526 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-nwkbp" "namespace"="default"
E0729 09:32:06.408928   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-m4khm: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-m4khm" "namespace"="default"
I0729 09:32:07.393545   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:32:07.393591   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-vmxpv" "namespace"="md-test" 
I0729 09:32:07.397615   10526 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
I0729 09:32:07.397705   10526 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-d5cr2-6657c7fddb-4j25t" "namespace"="md-test" 
E0729 09:32:07.402049   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-d5cr2-cdfc6fd6c-snhq9\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-d5cr2-cdfc6fd6c-snhq9" "namespace"="md-test"

------------------------------
• [SLOW TEST:15.065 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
  /home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:248
------------------------------


Ran 16 of 16 Specs in 26.777 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (26.78s)
I0729 09:32:07.513594   10526 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-n9m8b" "namespace"="default" "count"=1
PASS
I0729 09:32:07.513630   10526 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-n9m8b" "namespace"="default" "descendants"="Control plane machines: test6-nwkbp" "indirect descendants count"=0
Tearing down test suite
I0729 09:32:07.514070   10526 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0729 09:32:07.514094   10526 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0729 09:32:07.514128   10526 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0729 09:32:07.514148   10526 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0729 09:32:07.514168   10526 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0729 09:32:07.514170   10526 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0729 09:32:07.514167   10526 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0729 09:32:07.515963   10526 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Patch http://127.0.0.1:38727/apis/cluster.x-k8s.io/v1alpha3/namespaces/default/clusters/test6-n9m8b/status: EOF" "controller"="cluster" "name"="test6-n9m8b" "namespace"="default"
E0729 09:32:07.554448   10526 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:38727/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1285&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:38727: connect: connection refused
E0729 09:32:07.554499   10526 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:38727/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1285&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:38727: connect: connection refused
E0729 09:32:07.554722   10526 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:38727/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1285&timeout=10s&timeoutSeconds=569&watch=true: dial tcp 127.0.0.1:38727: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	85.445s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0729 09:30:56.194808   11026 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0729 09:30:56.194831   11026 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0729 09:30:56.195221   11026 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0729 09:30:56.196113   11026 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0729 09:30:56.196301   11026 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=45503
I0729 09:30:56.196521   11026 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0729 09:30:58.368261   11026 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-5tgc9/test-cluster"
•E0729 09:30:58.833891   11026 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-5dxqm/test-cluster"
•E0729 09:30:59.281119   11026 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:40891/?timeout=50ms: dial tcp 127.0.0.1:40891: connect: connection refused"  "cluster"="cluster-cache-test-jg8fg/test-cluster"
•I0729 09:30:59.516898   11026 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0729 09:30:59.617809   11026 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0729 09:30:59.617885   11026 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0729 09:30:59.883259   11026 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0729 09:30:59.898256   11026 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0729 09:31:00.098780   11026 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0729 09:31:00.098842   11026 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0729 09:31:00.098913   11026 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0729 09:31:00.623872   11026 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0729 09:31:00.624127   11026 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 09:31:00.624170   11026 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-946096115/tls.crt: no such file or directory"  
I0729 09:31:00.624227   11026 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0729 09:31:00.668630   11026 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:43375/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:43375: connect: connection refused


Ran 5 of 5 Specs in 16.128 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.13s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.317s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 208 lines ...
=== RUN   TestReconcileNoClusterOwnerRef
I0729 09:31:09.392370   11585 controller.go:130]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0729 09:31:09.393694   11585 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0729 09:31:09.394315   11585 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0729 09:31:09.394473   11585 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0729 09:31:29.215887   11585 scale.go:173]  "msg"="Waiting for machines to be deleted" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Machines"=""
=== RUN   TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue
I0729 09:31:29.216016   11585 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: 1627551054
Will run 1 of 1 specs

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

Ran 1 of 1 Specs in 0.028 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.03s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0729 09:31:29.252452   11585 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-35v4lb" "kubeadmControlPlane"="kcp-foo-35v4lb" "namespace"="test" 
I0729 09:31:32.677460   11585 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-35v4lb" "kubeadmControlPlane"="kcp-foo-35v4lb" "namespace"="test" "needRollout"=["kcp-foo-35v4lb-vwjcp"]
I0729 09:31:32.677646   11585 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-35v4lb" "kubeadmControlPlane"="kcp-foo-35v4lb" "namespace"="test" "failures"="[machine kcp-foo-35v4lb-lh7mr does not have APIServerPodHealthy condition, machine kcp-foo-35v4lb-lh7mr does not have ControllerManagerPodHealthy condition, machine kcp-foo-35v4lb-lh7mr does not have SchedulerPodHealthy condition, machine kcp-foo-35v4lb-lh7mr does not have EtcdPodHealthy condition, machine kcp-foo-35v4lb-lh7mr does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (3.43s)
... skipping 60 lines ...
==================================
Random Seed: 1627551053
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: 1627551053
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0729 09:31:09.649625   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:31:17.972805   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:31:26.961838   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:31:38.092160   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:31:54.565464   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:32:07.574038   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:32:25.221507   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:32:46.144856   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:33:17.161368   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0729 09:34:02.318561   11547 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
E0729 09:34:02.328567   11547 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 09:34:02.328603   11547 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-350775264/tls.crt: no such file or directory"  
E0729 09:34:02.328622   11547 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 09:34:02.328639   11547 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-350775264/tls.crt: no such file or directory"  
I0729 09:34:02.328998   11547 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.756s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0729 09:31:16.714015   11872 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0729 09:31:16.714166   11872 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0729 09:31:16.814618   11872 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0729 09:31:16.915028   11872 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0729 09:31:16.915091   11872 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0729 09:31:17.024987   11872 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-3giizk"} 
E0729 09:31:17.063919   11872 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•I0729 09:31:18.114529   11872 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-la98zr"} 
E0729 09:31:18.159468   11872 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0729 09:31:19.220376   11872 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0729 09:31:20.240764   11872 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0729 09:31:21.369440   11872 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0729 09:31:22.400340   11872 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset2\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset2" "namespace"="default"
•E0729 09:31:23.416557   11872 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•I0729 09:31:23.424567   11872 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0729 09:31:23.424660   11872 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0729 09:31:23.424736   11872 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 5 of 5 Specs in 20.924 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.92s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	21.013s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0729 09:31:08.266928   12052 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 91 lines ...
•I0729 09:31:20.252782   12052 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0729 09:31:20.283170   12052 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0729 09:31:20.334517   12052 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0729 09:31:20.336427   12052 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0729 09:31:20.356492   12052 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0729 09:31:20.385344   12052 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0729 09:31:20.387615   12052 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 09:31:20.387669   12052 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-375379779/tls.crt: no such file or directory"  
E0729 09:31:20.387689   12052 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0729 09:31:20.387707   12052 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-375379779/tls.crt: no such file or directory"  
I0729 09:31:20.388769   12052 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0729 09:31:20.435621   12052 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


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

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 24 lines ...
STEP: Creating a new patch helper
STEP: Updating the object spec
STEP: Updating the object status
STEP: Setting Ready condition
STEP: Patching the object
•I0729 09:31:49.402710   15096 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0729 09:31:49.403154   15096 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0729 09:31:49.403230   15096 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-911047963/tls.crt: no such file or directory"  



Summarizing 1 Failure:

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

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