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-26 15:04
Elapsed4m31s
Revision14ec45d7046f1a998b93360890e8f0879c40e036
Refs 5013

No Test Failures!


Error lines from build-log.txt

... skipping 781 lines ...
I0726 15:06:41.140035    8443 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0726 15:06:41.775455    8443 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" 
•I0726 15:06:41.787087    8443 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 15.213 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (15.21s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	59.504s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 310 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1401 lines ...
I0726 15:06:15.182187   10494 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0726 15:06:15.182356   10494 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0726 15:06:15.182384   10494 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
2021/07/26 15:06:15 http: TLS handshake error from 127.0.0.1:57664: EOF
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0726 15:06:15.474170   10494 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"
I0726 15:06:15.477703   10494 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
I0726 15:06:15.478234   10494 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"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_is_marked_ready_on_cluster
... skipping 102 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0726 15:06:15.523915   10494 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
I0726 15:06:15.525645   10494 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"
E0726 15:06:15.544614   10494 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
I0726 15:06:15.546401   10494 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.02s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.02s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0726 15:06:15.857702   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0726 15:06:15.861772   10494 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0726 15:06:15.869681   10494 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-tjdk2" "namespace"="test-machine-watches-pvvvt" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0726 15:06:15.869773   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0726 15:06:15.979103   10494 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-tjdk2" "namespace"="test-machine-watches-pvvvt" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0726 15:06:15.979192   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0726 15:06:16.079996   10494 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-tjdk2" "namespace"="test-machine-watches-pvvvt" "noderef"="node-1"
E0726 15:06:16.091673   10494 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0726 15:06:16.091735   10494 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0726 15:06:16.144892   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-tjdk2\" in namespace \"test-machine-watches-pvvvt\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-tjdk2" "namespace"="test-machine-watches-pvvvt"
E0726 15:06:17.152242   10494 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-tjdk2\" in namespace \"test-machine-watches-pvvvt\", requeuing: requeue in 1s"  
E0726 15:06:17.158150   10494 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-tjdk2\" in namespace \"test-machine-watches-pvvvt\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-tjdk2\" in namespace \"test-machine-watches-pvvvt\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-tjdk2" "namespace"="test-machine-watches-pvvvt"
--- PASS: TestWatches (1.64s)
=== 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
I0726 15:06:17.482962   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-xl8q6" "namespace"="test-machine-watches-pvvvt" "count"=1
I0726 15:06:17.483040   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-xl8q6" "namespace"="test-machine-watches-pvvvt" "descendants"="Worker machines: machine-created-tjdk2" "indirect descendants count"=0
I0726 15:06:17.499885   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-xl8q6" "namespace"="test-machine-watches-pvvvt" "count"=1
I0726 15:06:17.499944   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-xl8q6" "namespace"="test-machine-watches-pvvvt" "descendants"="Worker machines: machine-created-tjdk2" "indirect descendants count"=0
I0726 15:06:18.158879   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xl8q6" "machine"="machine-created-tjdk2" "namespace"="test-machine-watches-pvvvt" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"471ffb5d-f886-409f-8524-6600d531dcc2","apiVersion":"v1"}
E0726 15:06:18.210512   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-tjdk2\" not found" "controller"="machine" "name"="machine-created-tjdk2" "namespace"="test-machine-watches-pvvvt"
E0726 15:06:19.263777   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-rnbfm\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-ckbw2\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-ckbw2: secrets \"machine-reconcile-ckbw2-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-rnbfm" "namespace"="default"
I0726 15:06:20.264296   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-ckbw2" "machine"="machine-created-rnbfm" "namespace"="default" "cause"="noderef is nil" "node"=null
I0726 15:06:20.298646   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-ckbw2" "machine"="machine-created-rnbfm" "namespace"="default" "cause"="noderef is nil" "node"=null
I0726 15:06:20.326796   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-ckbw2" "machine"="machine-created-rnbfm" "namespace"="default" "cause"="noderef is nil" "node"=null
E0726 15:06:20.357923   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-rnbfm\" not found" "controller"="machine" "name"="machine-created-rnbfm" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.18s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.18s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.01s)
... skipping 4 lines ...
I0726 15:06:20.372033   10494 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0726 15:06:20.372151   10494 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
I0726 15:06:20.379526   10494 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"
I0726 15:06:20.379630   10494 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
E0726 15:06:20.383937   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-ckbw2\" not found" "controller"="cluster" "name"="machine-reconcile-ckbw2" "namespace"="default"
I0726 15:06:20.384755   10494 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"
I0726 15:06:20.384854   10494 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.02s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.01s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
... skipping 121 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0726 15:06:20.533348   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rv7b2" "namespace"="test-mhc-kkg6r" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0726 15:06:20.564230   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0726 15:06:20.565637   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-42fqv\" not found"  "cluster"="test-mhc-kkg6r/test-cluster-42fqv"
E0726 15:06:20.589764   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-rv7b2\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-rv7b2\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-rv7b2" "namespace"="test-mhc-kkg6r"
=== 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
I0726 15:06:21.590059   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rv7b2" "namespace"="test-mhc-kkg6r" 
I0726 15:06:21.590177   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8swxw" "namespace"="test-mhc-9vbtv" 
I0726 15:06:21.590206   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qztp4" "namespace"="test-mhc-k45sq" 
I0726 15:06:21.590237   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4t2tj" "namespace"="test-mhc-vp7zj" 
I0726 15:06:21.616989   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:06:21.632318   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4t2tj" "namespace"="test-mhc-vp7zj" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0726 15:06:21.719039   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4t2tj" "namespace"="test-mhc-vp7zj" 
E0726 15:06:21.734969   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vp7zj/test-cluster-sds6s"
E0726 15:06:21.738987   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-sds6s\" not found" "controller"="cluster" "name"="test-cluster-sds6s" "namespace"="test-mhc-vp7zj"
I0726 15:06:21.745425   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68z6n" "namespace"="test-mhc-gksk9" 
I0726 15:06:21.760687   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:06:21.779392   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68z6n" "namespace"="test-mhc-gksk9" 
E0726 15:06:21.850886   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gksk9/test-cluster-prsr8"
I0726 15:06:21.855694   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-68z6n" "namespace"="test-mhc-gksk9" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0726 15:06:21.872590   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
inframachine created: test-mhc-machine-infra-bq89c
I0726 15:06:21.901101   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-kf956
I0726 15:06:21.921370   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.927684   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.928419   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.928993   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.931624   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.931939   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:21.946469   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.946918   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:21.948531   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.948942   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:21.959945   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.960406   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:21.969838   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.970179   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:21.986935   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.987411   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:21.997382   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:21.997723   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
E0726 15:06:22.015452   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-29dvj, got []"  "node"="test-mhc-node-29dvj"
E0726 15:06:22.015737   10494 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-29dvj"
node created: test-mhc-node-29dvj
I0726 15:06:22.017034   10494 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7" "noderef"="test-mhc-node-29dvj"
E0726 15:06:22.021111   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-29dvj, got []"  "node"="test-mhc-node-29dvj"
E0726 15:06:22.021155   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-29dvj, got []"  "node"="test-mhc-node-29dvj"
E0726 15:06:22.021388   10494 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-29dvj"
E0726 15:06:22.021431   10494 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-29dvj"
I0726 15:06:22.026019   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
inframachine created: test-mhc-machine-infra-xmbks
I0726 15:06:22.044097   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
machine created: test-mhc-machine-jss2t
I0726 15:06:22.051871   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.063533   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
... skipping 41 lines ...
I0726 15:06:22.204032   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.207355   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.208921   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.210139   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.217199   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.236192   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.236799   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-jss2t/"
node created: test-mhc-node-xtg84
E0726 15:06:22.254498   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xtg84, got []"  "node"="test-mhc-node-xtg84"
I0726 15:06:22.254671   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.255321   10494 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-qtkr7/test-mhc-w749n/test-mhc-machine-jss2t/"
E0726 15:06:22.257727   10494 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-xtg84"
I0726 15:06:22.262266   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.269042   10494 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7" "noderef"="test-mhc-node-xtg84"
I0726 15:06:22.302175   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.303645   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
Cleaning up nodes, machines and infra machines.
I0726 15:06:22.312706   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.313214   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:22.330487   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:22.331011   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qtkr7/test-mhc-w749n/test-mhc-machine-kf956/"
I0726 15:06:22.331458   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qtkr7/test-mhc-w749n/test-mhc-machine-jss2t/"
E0726 15:06:22.349570   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qtkr7/test-cluster-z6rf4"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-s6zgd
machine created: test-mhc-machine-qzg6j
E0726 15:06:22.468394   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-w749n\" not found" "controller"="machinehealthcheck" "name"="test-mhc-w749n" "namespace"="test-mhc-qtkr7"
E0726 15:06:22.487383   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
E0726 15:06:22.759868   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-pvvvt/machine-reconcile-xl8q6"
I0726 15:06:23.468727   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:23.482801   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0726 15:06:23.499198   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:23.583459   10494 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-nbggs/test-mhc-cfqzt/test-mhc-machine-qzg6j/"
node created: test-mhc-node-78fpr
E0726 15:06:23.599080   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-78fpr, got []"  "node"="test-mhc-node-78fpr"
inframachine created: test-mhc-machine-infra-h2tfb
I0726 15:06:23.638959   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w749n" "namespace"="test-mhc-qtkr7" 
I0726 15:06:23.639062   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
machine created: test-mhc-machine-2jwjp
I0726 15:06:23.707552   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:23.723710   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
... skipping 306 lines ...
I0726 15:06:24.485316   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.488623   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.491051   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.493476   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.495465   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.497734   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
E0726 15:06:24.499549   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:24.500152   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.502426   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.504846   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.507128   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.509508   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:24.511588   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
... skipping 378 lines ...
I0726 15:06:25.544061   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.545132   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.546170   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.548295   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.549577   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.550575   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
E0726 15:06:25.550626   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:25.551775   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.553928   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.556059   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.558248   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.560344   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:25.562528   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
... skipping 341 lines ...
I0726 15:06:26.552692   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:26.554824   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:26.557417   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:26.559201   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:26.560335   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:26.563240   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
E0726 15:06:26.563816   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:26.564340   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:26.564677   10494 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-nbggs/test-mhc-cfqzt/test-mhc-machine-2jwjp/"
I0726 15:06:26.576122   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:26.576528   10494 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-nbggs/test-mhc-cfqzt/test-mhc-machine-2jwjp/"
E0726 15:06:26.594765   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nwnhh, got []"  "node"="test-mhc-node-nwnhh"
node created: test-mhc-node-nwnhh
I0726 15:06:26.603384   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
inframachine created: test-mhc-machine-infra-hj5zs
I0726 15:06:26.651164   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
machine created: test-mhc-machine-568gp
I0726 15:06:26.664482   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
... skipping 249 lines ...
I0726 15:06:27.550937   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.562403   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.567044   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.575500   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.580336   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.581747   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
E0726 15:06:27.583665   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:27.584120   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.586761   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.590403   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.593515   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.601964   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:27.604585   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
... skipping 293 lines ...
I0726 15:06:28.603340   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.604739   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.606302   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.612116   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.614491   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.617906   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
E0726 15:06:28.634566   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:28.639071   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.640627   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.642057   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.643602   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.645074   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:28.646564   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
... skipping 283 lines ...
I0726 15:06:29.645262   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.648219   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.650266   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.651672   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.653003   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.654378   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.654812   10494 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-nbggs/test-mhc-cfqzt/test-mhc-machine-568gp/"
E0726 15:06:29.657774   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
E0726 15:06:29.676650   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w4dwt, got []"  "node"="test-mhc-node-w4dwt"
node created: test-mhc-node-w4dwt
I0726 15:06:29.696572   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.697185   10494 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-nbggs/test-mhc-cfqzt/test-mhc-machine-568gp/"
Cleaning up nodes, machines and infra machines.
I0726 15:06:29.701261   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.701769   10494 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-nbggs/test-mhc-cfqzt/test-mhc-machine-568gp/test-mhc-node-w4dwt"
I0726 15:06:29.725803   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.726360   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-nbggs/test-mhc-cfqzt/test-mhc-machine-568gp/"
Cleaning up nodes, machines and infra machines.
I0726 15:06:29.748284   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:29.748862   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-nbggs/test-mhc-cfqzt/test-mhc-machine-qzg6j/"
I0726 15:06:29.786628   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cdwzg" "namespace"="test-mhc-nbggs" "count"=2
I0726 15:06:29.786704   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cdwzg" "namespace"="test-mhc-nbggs" "descendants"="Worker machines: test-mhc-machine-qzg6j,test-mhc-machine-2jwjp,test-mhc-machine-568gp" "indirect descendants count"=1
I0726 15:06:29.791020   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cdwzg" "namespace"="test-mhc-nbggs" "count"=2
I0726 15:06:29.791084   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cdwzg" "namespace"="test-mhc-nbggs" "descendants"="Worker machines: test-mhc-machine-2jwjp,test-mhc-machine-568gp,test-mhc-machine-qzg6j" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0726 15:06:29.924078   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-nbggs/test-mhc-cfqzt/test-mhc-machine-568gp/"
E0726 15:06:29.931331   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-cfqzt\" not found" "controller"="machinehealthcheck" "name"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs"
inframachine created: test-mhc-machine-infra-dwf88
machine created: test-mhc-machine-849ft
I0726 15:06:30.658540   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cdwzg" "machine"="test-mhc-machine-2jwjp" "namespace"="test-mhc-nbggs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nwnhh"}
E0726 15:06:30.709030   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2jwjp\" not found" "controller"="machine" "name"="test-mhc-machine-2jwjp" "namespace"="test-mhc-nbggs"
I0726 15:06:30.931680   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:30.961252   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:06:31.000469   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cfqzt" "namespace"="test-mhc-nbggs" 
I0726 15:06:31.000540   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:31.005600   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:31.026489   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:31.067477   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:31.148517   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:31.309598   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:31.630613   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:31.709731   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:32.271777   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:32.710261   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cdwzg" "machine"="test-mhc-machine-568gp" "namespace"="test-mhc-nbggs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-w4dwt"}
E0726 15:06:32.756318   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-568gp\" not found" "controller"="machine" "name"="test-mhc-machine-568gp" "namespace"="test-mhc-nbggs"
I0726 15:06:33.552840   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:33.756955   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:34.757529   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cdwzg" "machine"="test-mhc-machine-qzg6j" "namespace"="test-mhc-nbggs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-78fpr"}
I0726 15:06:34.790753   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cdwzg" "namespace"="test-mhc-nbggs" "count"=1
I0726 15:06:34.790868   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cdwzg" "namespace"="test-mhc-nbggs" "descendants"="Worker machines: test-mhc-machine-qzg6j" "indirect descendants count"=0
E0726 15:06:34.843617   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qzg6j\" not found" "controller"="machine" "name"="test-mhc-machine-qzg6j" "namespace"="test-mhc-nbggs"
I0726 15:06:35.852211   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:35.859896   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:35.860167   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:35.878708   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:35.880263   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-s2ft5, got []"  "node"="test-mhc-node-s2ft5"
node created: test-mhc-node-s2ft5
E0726 15:06:35.880504   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-s2ft5, got []"  "node"="test-mhc-node-s2ft5"
I0726 15:06:35.887256   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
inframachine created: test-mhc-machine-infra-njwjc
machine created: test-mhc-machine-sqwrl
I0726 15:06:35.918060   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:35.933803   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:35.938921   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:35.960130   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:36.001509   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:36.083480   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:36.244870   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:36.566198   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:36.860307   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:37.209878   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.877890   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.885882   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.886954   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.889398   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.897620   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.901352   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.908808   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.913068   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:37.913365   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
node created: test-mhc-node-5hjfb
E0726 15:06:37.923606   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5hjfb, got []"  "node"="test-mhc-node-5hjfb"
E0726 15:06:37.923729   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5hjfb, got []"  "node"="test-mhc-node-5hjfb"
inframachine created: test-mhc-machine-infra-r866t
I0726 15:06:37.937934   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
machine created: test-mhc-machine-4pffc
I0726 15:06:37.953958   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:37.973227   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:38.491680   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:38.913847   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
E0726 15:06:39.806901   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-nbggs/test-cluster-cdwzg"
I0726 15:06:39.924236   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:39.936729   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:39.942819   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:39.966081   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:39.974161   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:39.990686   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:39.997401   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:39.998052   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:40.033136   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
E0726 15:06:40.057922   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-76wtw, got []"  "node"="test-mhc-node-76wtw"
node created: test-mhc-node-76wtw
I0726 15:06:40.064841   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
Cleaning up nodes, machines and infra machines.
I0726 15:06:40.081553   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
Cleaning up nodes, machines and infra machines.
I0726 15:06:40.135527   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-vng87" "namespace"="test-mhc-d2k5t" "count"=2
... skipping 5 lines ...
machine created: test-mhc-machine-n5g2s
I0726 15:06:40.319610   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:40.335962   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:06:40.355071   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqp6t" "namespace"="test-mhc-d2k5t" 
I0726 15:06:40.355175   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:40.359901   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
E0726 15:06:40.997903   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:41.998510   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vng87" "machine"="test-mhc-machine-849ft" "namespace"="test-mhc-d2k5t" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-s2ft5"}
E0726 15:06:42.050496   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-849ft\" not found" "controller"="machine" "name"="test-mhc-machine-849ft" "namespace"="test-mhc-d2k5t"
I0726 15:06:43.057655   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vng87" "machine"="test-mhc-machine-sqwrl" "namespace"="test-mhc-d2k5t" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5hjfb"}
E0726 15:06:43.120695   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-sqwrl\" not found" "controller"="machine" "name"="test-mhc-machine-sqwrl" "namespace"="test-mhc-d2k5t"
I0726 15:06:44.121296   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vng87" "machine"="test-mhc-machine-4pffc" "namespace"="test-mhc-d2k5t" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-76wtw"}
E0726 15:06:44.166701   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4pffc\" not found" "controller"="machine" "name"="test-mhc-machine-4pffc" "namespace"="test-mhc-d2k5t"
E0726 15:06:45.152544   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-d2k5t/test-cluster-vng87"
I0726 15:06:45.175627   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:45.181670   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
E0726 15:06:45.181724   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
E0726 15:06:45.219056   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d9mrl, got []"  "node"="test-mhc-node-d9mrl"
node created: test-mhc-node-d9mrl
I0726 15:06:45.225800   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
inframachine created: test-mhc-machine-infra-4796n
I0726 15:06:45.245427   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
machine created: test-mhc-machine-dzzp6
I0726 15:06:45.251329   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:45.257873   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
E0726 15:06:46.182526   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:47.197672   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:47.226192   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:47.241556   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:47.247079   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:47.254935   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:47.259855   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
E0726 15:06:47.260132   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
E0726 15:06:47.360312   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mg2hm, got []"  "node"="test-mhc-node-mg2hm"
node created: test-mhc-node-mg2hm
I0726 15:06:47.367635   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
inframachine created: test-mhc-machine-infra-cx2fk
I0726 15:06:47.386443   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
machine created: test-mhc-machine-p6m8l
I0726 15:06:47.393069   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:47.399919   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.282010   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.299096   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.306436   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.322402   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.328109   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.339502   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
E0726 15:06:48.347076   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:48.347120   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
Cleaning up nodes, machines and infra machines.
I0726 15:06:48.414012   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
Cleaning up nodes, machines and infra machines.
I0726 15:06:48.433959   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.434530   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jz68x/test-mhc-6qv85/test-mhc-machine-n5g2s/"
I0726 15:06:48.457739   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:48.458334   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jz68x/test-mhc-6qv85/test-mhc-machine-n5g2s/"
I0726 15:06:48.458826   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jz68x/test-mhc-6qv85/test-mhc-machine-dzzp6/"
I0726 15:06:48.477496   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-vm27j" "namespace"="test-mhc-jz68x" "count"=2
I0726 15:06:48.477587   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vm27j" "namespace"="test-mhc-jz68x" "descendants"="Worker machines: test-mhc-machine-n5g2s,test-mhc-machine-dzzp6,test-mhc-machine-p6m8l" "indirect descendants count"=1
I0726 15:06:48.482761   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-vm27j" "namespace"="test-mhc-jz68x" "count"=2
I0726 15:06:48.482826   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vm27j" "namespace"="test-mhc-jz68x" "descendants"="Worker machines: test-mhc-machine-n5g2s,test-mhc-machine-dzzp6,test-mhc-machine-p6m8l" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
E0726 15:06:48.495088   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6qv85\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6qv85" "namespace"="test-mhc-jz68x"
inframachine created: test-mhc-machine-infra-qm9qf
machine created: test-mhc-machine-82bf5
I0726 15:06:49.348160   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vm27j" "machine"="test-mhc-machine-n5g2s" "namespace"="test-mhc-jz68x" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-d9mrl"}
E0726 15:06:49.395683   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-n5g2s\" not found" "controller"="machine" "name"="test-mhc-machine-n5g2s" "namespace"="test-mhc-jz68x"
I0726 15:06:49.495482   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qv85" "namespace"="test-mhc-jz68x" 
I0726 15:06:49.495587   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:49.518126   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:06:49.643169   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:49.644287   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:49.646211   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
... skipping 360 lines ...
I0726 15:06:50.453351   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.455635   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.457409   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.459183   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.460869   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.462557   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
E0726 15:06:50.464211   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dzzp6\" not found" "controller"="machine" "name"="test-mhc-machine-dzzp6" "namespace"="test-mhc-jz68x"
I0726 15:06:50.464309   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.466032   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.467731   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.469399   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.471117   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:50.472863   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
... skipping 509 lines ...
I0726 15:06:51.530944   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.533620   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.535663   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.537353   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.539118   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.540844   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
E0726 15:06:51.541364   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-p6m8l\" not found" "controller"="machine" "name"="test-mhc-machine-p6m8l" "namespace"="test-mhc-jz68x"
I0726 15:06:51.542659   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.544357   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.546069   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.547773   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.549483   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:51.554345   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
... skipping 461 lines ...
I0726 15:06:52.551536   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.553244   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.554507   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.555089   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.556761   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.558500   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.558769   10494 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-4rz7h/test-mhc-gxfgn/test-mhc-machine-82bf5/"
E0726 15:06:52.559021   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:52.568434   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.568713   10494 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-4rz7h/test-mhc-gxfgn/test-mhc-machine-82bf5/"
E0726 15:06:52.659845   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ps6vj, got []"  "node"="test-mhc-node-ps6vj"
node created: test-mhc-node-ps6vj
E0726 15:06:52.660695   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ps6vj, got []"  "node"="test-mhc-node-ps6vj"
I0726 15:06:52.670076   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.690876   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.694419   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.694778   10494 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-4rz7h/test-mhc-gxfgn/test-mhc-machine-82bf5/test-mhc-node-ps6vj"
I0726 15:06:52.710042   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.710425   10494 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-4rz7h/test-mhc-gxfgn/test-mhc-machine-82bf5/test-mhc-node-ps6vj"
Cleaning up nodes, machines and infra machines.
I0726 15:06:52.721571   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.721907   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4rz7h/test-mhc-gxfgn/test-mhc-machine-82bf5/"
I0726 15:06:52.732202   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.732576   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4rz7h/test-mhc-gxfgn/test-mhc-machine-82bf5/"
I0726 15:06:52.738836   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
I0726 15:06:52.739162   10494 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4rz7h/test-mhc-gxfgn/test-mhc-machine-82bf5/"
I0726 15:06:52.740996   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-wxszd" "namespace"="test-mhc-4rz7h" "descendants"="Worker machines: test-mhc-machine-82bf5" "indirect descendants count"=1
I0726 15:06:52.745813   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-wxszd" "namespace"="test-mhc-4rz7h" "descendants"="Worker machines: test-mhc-machine-82bf5" "indirect descendants count"=1
I0726 15:06:52.754459   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gxfgn" "namespace"="test-mhc-4rz7h" 
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0726 15:06:52.833692   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" "creating"=1 "need"=1
I0726 15:06:52.833756   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" 
I0726 15:06:52.847077   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-8xp5v-k68f2\"" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" 
I0726 15:06:52.923597   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:52.935790   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:06:53.054446   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:53.062260   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
E0726 15:06:53.496304   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jz68x/test-cluster-vm27j"
E0726 15:06:53.559492   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:54.054682   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:54.560052   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wxszd" "machine"="test-mhc-machine-82bf5" "namespace"="test-mhc-4rz7h" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ps6vj"}
E0726 15:06:54.647145   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-82bf5\" not found" "controller"="machine" "name"="test-mhc-machine-82bf5" "namespace"="test-mhc-4rz7h"
I0726 15:06:55.055823   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.668468   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.668548   10494 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.677242   10494 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.677247   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.686895   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
... skipping 4 lines ...
I0726 15:06:55.715082   10494 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.720124   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.720180   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.734547   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:55.734592   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.056867   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.057312   10494 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-mtz8t/test-mhc-mzsr5/mhc-ms-8xp5v-k68f2/"
I0726 15:06:56.067884   10494 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.080766   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.080832   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.091026   10494 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.101944   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.101994   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.107698   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.108178   10494 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-mtz8t/test-mhc-mzsr5/mhc-ms-8xp5v-k68f2/"
I0726 15:06:56.165715   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-vx9cn" "namespace"="test-mhc-mtz8t" "count"=1
I0726 15:06:56.165780   10494 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-vx9cn" "namespace"="test-mhc-mtz8t" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-8xp5v"
I0726 15:06:56.167956   10494 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-8xp5v" "namespace"="test-mhc-mtz8t" "machine"="mhc-ms-8xp5v-k68f2"
I0726 15:06:56.173441   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vx9cn" "namespace"="test-mhc-mtz8t" "descendants"="Machine sets: mhc-ms-8xp5v;Worker machines: mhc-ms-8xp5v-k68f2" "indirect descendants count"=1
I0726 15:06:56.175891   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vx9cn" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" "cause"="cluster is being deleted" "node"=null
I0726 15:06:56.177431   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.177760   10494 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-mtz8t/test-mhc-mzsr5/mhc-ms-8xp5v-k68f2/"
I0726 15:06:56.188916   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mzsr5" "namespace"="test-mhc-mtz8t" 
I0726 15:06:56.192356   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vx9cn" "namespace"="test-mhc-mtz8t" "descendants"="Worker machines: mhc-ms-8xp5v-k68f2" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0726 15:06:56.234737   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vx9cn" "machine"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t" "cause"="cluster is being deleted" "node"=null
E0726 15:06:56.276712   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-8xp5v-k68f2\" not found" "controller"="machine" "name"="mhc-ms-8xp5v-k68f2" "namespace"="test-mhc-mtz8t"
I0726 15:06:56.284264   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
inframachine created: test-mhc-machine-infra-9ccnc
I0726 15:06:56.321132   10494 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-n88js
I0726 15:06:56.342648   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:56.348848   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
... skipping 416 lines ...
I0726 15:06:57.293436   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.294770   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.295862   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.297848   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.301610   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.303184   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
E0726 15:06:57.334884   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bjbvm, got []"  "node"="test-mhc-node-bjbvm"
node created: test-mhc-node-bjbvm
E0726 15:06:57.334977   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bjbvm, got []"  "node"="test-mhc-node-bjbvm"
E0726 15:06:57.335004   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bjbvm, got []"  "node"="test-mhc-node-bjbvm"
I0726 15:06:57.343756   10494 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-n88js" "namespace"="test-mhc-6p9vp" "noderef"="test-mhc-node-bjbvm"
I0726 15:06:57.380889   10494 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-n88js" "target"="test-mhc-6p9vp/test-mhc-mbr28/test-mhc-machine-n88js/"
I0726 15:06:57.579045   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
E0726 15:06:57.679382   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
I0726 15:06:57.745667   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.761324   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
E0726 15:06:57.761607   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4rz7h/test-cluster-wxszd"
I0726 15:06:57.766512   10494 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-n88js" "target"="test-mhc-6p9vp/test-mhc-mbr28/test-mhc-machine-n88js/test-mhc-node-bjbvm"
I0726 15:06:57.791782   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
Cleaning up nodes, machines and infra machines.
I0726 15:06:57.799121   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.845143   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mbr28" "namespace"="test-mhc-6p9vp" 
I0726 15:06:57.866410   10494 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-g5fqs" "namespace"="test-mhc-6p9vp" "count"=1
I0726 15:06:57.866522   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-g5fqs" "namespace"="test-mhc-6p9vp" "descendants"="Worker machines: test-mhc-machine-n88js" "indirect descendants count"=0
... skipping 253 lines ...
I0726 15:06:58.735875   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.737679   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.739557   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.745522   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.747502   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.749385   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
E0726 15:06:58.750943   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-n88js\" not found" "controller"="machine" "name"="test-mhc-machine-n88js" "namespace"="test-mhc-6p9vp"
I0726 15:06:58.751174   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.753002   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.754802   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.756591   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.758422   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:58.760222   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
... skipping 524 lines ...
I0726 15:06:59.755774   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.757976   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.759116   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.759811   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.761081   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.763100   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
E0726 15:06:59.763424   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
I0726 15:06:59.763851   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.767754   10494 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-2bdwd" "target"="test-mhc-v9vkj/test-mhc-4zbl6/test-mhc-machine-2bdwd/"
I0726 15:06:59.784956   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
E0726 15:06:59.867968   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zrqd2, got []"  "node"="test-mhc-node-zrqd2"
E0726 15:06:59.868271   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zrqd2, got []"  "node"="test-mhc-node-zrqd2"
E0726 15:06:59.868436   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zrqd2, got []"  "node"="test-mhc-node-zrqd2"
node created: test-mhc-node-zrqd2
I0726 15:06:59.880602   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.905134   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.907885   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.915301   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.918895   10494 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-2bdwd" "target"="test-mhc-v9vkj/test-mhc-4zbl6/test-mhc-machine-2bdwd/test-mhc-node-zrqd2"
I0726 15:06:59.934626   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.941721   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.959860   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
Cleaning up nodes, machines and infra machines.
I0726 15:06:59.965704   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.969238   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
I0726 15:06:59.972756   10494 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-2bdwd" "target"="test-mhc-v9vkj/test-mhc-4zbl6/test-mhc-machine-2bdwd/"
I0726 15:06:59.984696   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fxrgp" "namespace"="test-mhc-v9vkj" "descendants"="Worker machines: test-mhc-machine-2bdwd" "indirect descendants count"=1
E0726 15:06:59.989086   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4zbl6\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj"
I0726 15:06:59.992293   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fxrgp" "namespace"="test-mhc-v9vkj" "descendants"="Worker machines: test-mhc-machine-2bdwd" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (39.50s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.06s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.07s)
... skipping 11 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.67s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.12s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0726 15:06:59.993349   10494 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
E0726 15:06:59.994449   10494 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
E0726 15:06:59.995651   10494 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0726 15:06:59.995818   10494 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
E0726 15:06:59.996105   10494 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
I0726 15:07:00.000593   10494 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0726 15:07:00.001344   10494 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0726 15:07:00.003284   10494 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
E0726 15:07:00.015251   10494 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
E0726 15:07:00.017521   10494 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 ...
I0726 15:07:00.155125   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-7r9jp-vs8tz\"" "machineset"="ms-7r9jp" "namespace"="ms-test" 
I0726 15:07:00.155213   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-7r9jp" "namespace"="ms-test" 
I0726 15:07:00.173527   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-7r9jp-477sf\"" "machineset"="ms-7r9jp" "namespace"="ms-test" 
I0726 15:07:00.270622   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-7r9jp" "namespace"="ms-test" "creating"=1 "need"=2
I0726 15:07:00.270666   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-7r9jp" "namespace"="ms-test" 
I0726 15:07:00.292260   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-7r9jp-mjgt6\"" "machineset"="ms-7r9jp" "namespace"="ms-test" 
E0726 15:07:00.399206   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.399220   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.399719   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.503187   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.503255   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.503402   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.503441   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.503450   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.503493   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-mjgt6-5jh5z, got []"  "node"="ms-7r9jp-mjgt6-5jh5z"
E0726 15:07:00.530403   10494 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-7r9jp-mjgt6-5jh5z for machine ms-test/ms-7r9jp-mjgt6: the cache is not started, can not read objects" "machineset"="ms-7r9jp" "namespace"="ms-test" 
E0726 15:07:00.538637   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.538637   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.538847   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.642635   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.642708   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.642715   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.642774   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.643029   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
E0726 15:07:00.643067   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-7r9jp-477sf-gssq9, got []"  "node"="ms-7r9jp-477sf-gssq9"
I0726 15:07:00.763946   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fxrgp" "machine"="test-mhc-machine-2bdwd" "namespace"="test-mhc-v9vkj" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zrqd2"}
I0726 15:07:00.767699   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7r9jp-mjgt6,ms-7r9jp-477sf" "indirect descendants count"=2
•I0726 15:07:00.770307   10494 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"
I0726 15:07:00.775200   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7r9jp-mjgt6,ms-7r9jp-477sf" "indirect descendants count"=2
I0726 15:07:00.779770   10494 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0726 15:07:00.779836   10494 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"
... skipping 16 lines ...
I0726 15:07:00.796334   10494 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"
•I0726 15:07:00.799085   10494 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"
I0726 15:07:00.800223   10494 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"
I0726 15:07:00.801617   10494 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0726 15:07:00.801670   10494 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0726 15:07:00.802515   10494 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0726 15:07:00.804396   10494 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" 
•E0726 15:07:00.812971   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2bdwd\" not found" "controller"="machine" "name"="test-mhc-machine-2bdwd" "namespace"="test-mhc-v9vkj"
I0726 15:07:00.869008   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0726 15:07:00.869059   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" 
I0726 15:07:00.880812   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-bs8sn-6657c7fddb-8tvkq\"" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" 
I0726 15:07:00.880870   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" 
I0726 15:07:00.891000   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-bs8sn-6657c7fddb-sn7pc\"" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" 
I0726 15:07:00.989358   10494 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbl6" "namespace"="test-mhc-v9vkj" 
... skipping 4 lines ...
I0726 15:07:01.041448   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-bs8sn-6657c7fddb-n9jpw\"" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" 
I0726 15:07:01.146255   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:07:01.146300   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" 
I0726 15:07:01.156694   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-bs8sn-6657c7fddb-cwrb9\"" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" 
I0726 15:07:01.202852   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0726 15:07:01.202908   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" 
E0726 15:07:01.203884   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mtz8t/test-cluster-vx9cn"
I0726 15:07:01.216597   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-bs8sn-cdfc6fd6c-mbsvx\"" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" 
E0726 15:07:01.277756   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-mbsvx-8tltq, got []"  "node"="md-bs8sn-cdfc6fd6c-mbsvx-8tltq"
E0726 15:07:01.277745   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-mbsvx-8tltq, got []"  "node"="md-bs8sn-cdfc6fd6c-mbsvx-8tltq"
E0726 15:07:01.285154   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-mbsvx-8tltq, got []"  "node"="md-bs8sn-cdfc6fd6c-mbsvx-8tltq"
E0726 15:07:01.285295   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-mbsvx-8tltq, got []"  "node"="md-bs8sn-cdfc6fd6c-mbsvx-8tltq"
E0726 15:07:01.285389   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-mbsvx-8tltq, got []"  "node"="md-bs8sn-cdfc6fd6c-mbsvx-8tltq"
E0726 15:07:01.285463   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-mbsvx-8tltq, got []"  "node"="md-bs8sn-cdfc6fd6c-mbsvx-8tltq"
E0726 15:07:01.312473   10494 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-bs8sn-cdfc6fd6c-mbsvx-8tltq for machine md-test/md-bs8sn-cdfc6fd6c-mbsvx: the cache is not started, can not read objects" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" 
I0726 15:07:01.954394   10494 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0726 15:07:01.954462   10494 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0726 15:07:01.966181   10494 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "machine"="md-bs8sn-6657c7fddb-cwrb9"
I0726 15:07:02.060984   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:02.061023   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:02.076561   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
... skipping 3 lines ...
I0726 15:07:02.088009   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-bs8sn-cdfc6fd6c-wmzgk\"" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" 
I0726 15:07:02.104122   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-qh88h" "namespace"="md-test" 
I0726 15:07:02.104156   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-qh88h" "namespace"="md-test" 
I0726 15:07:02.128467   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-n9jpw" "namespace"="md-test" 
I0726 15:07:02.128512   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-n9jpw" "namespace"="md-test" 
I0726 15:07:02.139865   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-bs8sn-6657c7fddb-cwrb9" "namespace"="md-test" "cause"="noderef is nil" "node"=null
E0726 15:07:02.201765   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
E0726 15:07:02.218424   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-wmzgk-fzvd8, got []"  "node"="md-bs8sn-cdfc6fd6c-wmzgk-fzvd8"
E0726 15:07:02.218525   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-wmzgk-fzvd8, got []"  "node"="md-bs8sn-cdfc6fd6c-wmzgk-fzvd8"
E0726 15:07:02.223081   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-wmzgk-fzvd8, got []"  "node"="md-bs8sn-cdfc6fd6c-wmzgk-fzvd8"
E0726 15:07:02.223199   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-wmzgk-fzvd8, got []"  "node"="md-bs8sn-cdfc6fd6c-wmzgk-fzvd8"
E0726 15:07:02.223224   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-wmzgk-fzvd8, got []"  "node"="md-bs8sn-cdfc6fd6c-wmzgk-fzvd8"
E0726 15:07:02.223252   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-wmzgk-fzvd8, got []"  "node"="md-bs8sn-cdfc6fd6c-wmzgk-fzvd8"
I0726 15:07:02.263413   10494 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0726 15:07:02.263463   10494 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0726 15:07:02.271917   10494 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "machine"="md-bs8sn-6657c7fddb-qh88h"
I0726 15:07:02.286213   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:07:02.286259   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" 
I0726 15:07:02.303789   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-bs8sn-cdfc6fd6c-g5cz2\"" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" 
E0726 15:07:02.371278   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-g5cz2-4mzv8, got []"  "node"="md-bs8sn-cdfc6fd6c-g5cz2-4mzv8"
E0726 15:07:02.371607   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-g5cz2-4mzv8, got []"  "node"="md-bs8sn-cdfc6fd6c-g5cz2-4mzv8"
E0726 15:07:02.477098   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-g5cz2-4mzv8, got []"  "node"="md-bs8sn-cdfc6fd6c-g5cz2-4mzv8"
E0726 15:07:02.477149   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-g5cz2-4mzv8, got []"  "node"="md-bs8sn-cdfc6fd6c-g5cz2-4mzv8"
E0726 15:07:02.477649   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-g5cz2-4mzv8, got []"  "node"="md-bs8sn-cdfc6fd6c-g5cz2-4mzv8"
E0726 15:07:02.477704   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-cdfc6fd6c-g5cz2-4mzv8, got []"  "node"="md-bs8sn-cdfc6fd6c-g5cz2-4mzv8"
I0726 15:07:02.516961   10494 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0726 15:07:02.517044   10494 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0726 15:07:02.520803   10494 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-bs8sn-6657c7fddb" "namespace"="md-test" "machine"="md-bs8sn-6657c7fddb-n9jpw"
I0726 15:07:02.667049   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0726 15:07:02.667107   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" 
I0726 15:07:02.684882   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-bs8sn-74d45c49c5-xdwtb\"" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" 
E0726 15:07:02.754248   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-xdwtb-pdxfg, got []"  "node"="md-bs8sn-74d45c49c5-xdwtb-pdxfg"
E0726 15:07:02.754267   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-xdwtb-pdxfg, got []"  "node"="md-bs8sn-74d45c49c5-xdwtb-pdxfg"
E0726 15:07:02.866793   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-xdwtb-pdxfg, got []"  "node"="md-bs8sn-74d45c49c5-xdwtb-pdxfg"
E0726 15:07:02.866858   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-xdwtb-pdxfg, got []"  "node"="md-bs8sn-74d45c49c5-xdwtb-pdxfg"
E0726 15:07:02.866807   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-xdwtb-pdxfg, got []"  "node"="md-bs8sn-74d45c49c5-xdwtb-pdxfg"
E0726 15:07:02.866893   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-xdwtb-pdxfg, got []"  "node"="md-bs8sn-74d45c49c5-xdwtb-pdxfg"
E0726 15:07:02.887520   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6p9vp/test-cluster-g5fqs"
I0726 15:07:02.906915   10494 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0726 15:07:02.906964   10494 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0726 15:07:02.910930   10494 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "machine"="md-bs8sn-cdfc6fd6c-wmzgk"
I0726 15:07:03.022095   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0726 15:07:03.022176   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" 
I0726 15:07:03.032604   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-bs8sn-74d45c49c5-dl57h\"" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" 
E0726 15:07:03.115962   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-dl57h-qxksd, got []"  "node"="md-bs8sn-74d45c49c5-dl57h-qxksd"
E0726 15:07:03.221048   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-dl57h-qxksd, got []"  "node"="md-bs8sn-74d45c49c5-dl57h-qxksd"
E0726 15:07:03.221097   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-dl57h-qxksd, got []"  "node"="md-bs8sn-74d45c49c5-dl57h-qxksd"
I0726 15:07:03.234152   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:03.234250   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:03.241549   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:03.241605   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:03.242304   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-bs8sn-6657c7fddb-qh88h" "namespace"="md-test" "cause"="noderef is nil" "node"=null
I0726 15:07:03.273230   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-bs8sn-6657c7fddb-n9jpw" "namespace"="md-test" "cause"="noderef is nil" "node"=null
I0726 15:07:03.277700   10494 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0726 15:07:03.277754   10494 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0726 15:07:03.286203   10494 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-bs8sn-cdfc6fd6c" "namespace"="md-test" "machine"="md-bs8sn-cdfc6fd6c-g5cz2"
I0726 15:07:03.311336   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-bs8sn-6657c7fddb-cwrb9" "namespace"="md-test" "cause"="noderef is nil" "node"=null
I0726 15:07:03.312445   10494 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:07:03.312541   10494 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" 
I0726 15:07:03.326745   10494 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-bs8sn-74d45c49c5-68s5b\"" "machineset"="md-bs8sn-74d45c49c5" "namespace"="md-test" 
E0726 15:07:03.341346   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-bs8sn-6657c7fddb-cwrb9\" not found" "controller"="machine" "name"="md-bs8sn-6657c7fddb-cwrb9" "namespace"="md-test"
E0726 15:07:03.365966   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-68s5b-fklj8, got []"  "node"="md-bs8sn-74d45c49c5-68s5b-fklj8"
E0726 15:07:03.475393   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-68s5b-fklj8, got []"  "node"="md-bs8sn-74d45c49c5-68s5b-fklj8"
E0726 15:07:03.475480   10494 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-bs8sn-74d45c49c5-68s5b-fklj8, got []"  "node"="md-bs8sn-74d45c49c5-68s5b-fklj8"
I0726 15:07:03.500171   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-bs8sn-74d45c49c5,md-bs8sn-cdfc6fd6c;Worker machines: md-bs8sn-6657c7fddb-8tvkq,md-bs8sn-6657c7fddb-sn7pc,md-bs8sn-6657c7fddb-qh88h,md-bs8sn-74d45c49c5-68s5b,md-bs8sn-cdfc6fd6c-mbsvx,md-bs8sn-6657c7fddb-n9jpw,md-bs8sn-74d45c49c5-xdwtb,md-bs8sn-74d45c49c5-dl57h" "indirect descendants count"=10
•I0726 15:07:03.506343   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-bs8sn-74d45c49c5,md-bs8sn-cdfc6fd6c;Worker machines: md-bs8sn-6657c7fddb-qh88h,md-bs8sn-74d45c49c5-68s5b,md-bs8sn-cdfc6fd6c-mbsvx,md-bs8sn-6657c7fddb-8tvkq,md-bs8sn-6657c7fddb-sn7pc,md-bs8sn-74d45c49c5-xdwtb,md-bs8sn-74d45c49c5-dl57h,md-bs8sn-6657c7fddb-n9jpw" "indirect descendants count"=10
•E0726 15:07:03.634466   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-2fjvz\" not found" "controller"="cluster" "name"="test1-2fjvz" "namespace"="default"
E0726 15:07:04.353987   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
I0726 15:07:04.751316   10494 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-dg8t9" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0726 15:07:04.866451   10494 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-dg8t9" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0726 15:07:04.873259   10494 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-dg8t9" "namespace"="default"
I0726 15:07:05.383207   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-bs8sn-6657c7fddb-qh88h" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0726 15:07:05.406282   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-bs8sn-6657c7fddb-qh88h\" not found" "controller"="machine" "name"="md-bs8sn-6657c7fddb-qh88h" "namespace"="md-test"
E0726 15:07:05.886785   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
•I0726 15:07:06.406806   10494 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-bs8sn-6657c7fddb-n9jpw" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0726 15:07:06.438643   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-bs8sn-6657c7fddb-n9jpw\" not found" "controller"="machine" "name"="md-bs8sn-6657c7fddb-n9jpw" "namespace"="md-test"
E0726 15:07:06.897343   10494 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-v9vkj/test-cluster-fxrgp"
I0726 15:07:06.897641   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7r9jp-mjgt6,ms-7r9jp-477sf" "indirect descendants count"=2
E0726 15:07:06.911026   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-87qnc\" not found" "controller"="cluster" "name"="test3-87qnc" "namespace"="default"
I0726 15:07:07.456141   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:07.456187   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:07.460359   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:07.460403   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
E0726 15:07:07.465376   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
E0726 15:07:07.911715   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
E0726 15:07:08.491324   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-xdwtb\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-xdwtb" "namespace"="md-test"
E0726 15:07:08.920922   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
•E0726 15:07:09.514797   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-dl57h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-dl57h" "namespace"="md-test"
I0726 15:07:09.921516   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-bs8sn-cdfc6fd6c,md-bs8sn-74d45c49c5;Worker machines: md-bs8sn-74d45c49c5-xdwtb,md-bs8sn-74d45c49c5-dl57h,md-bs8sn-74d45c49c5-68s5b,md-bs8sn-cdfc6fd6c-mbsvx,md-bs8sn-6657c7fddb-8tvkq,md-bs8sn-6657c7fddb-sn7pc" "indirect descendants count"=8
E0726 15:07:09.925964   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
E0726 15:07:10.542262   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
E0726 15:07:10.926874   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
E0726 15:07:11.542830   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-kf956\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-kf956" "namespace"="test-mhc-qtkr7"
E0726 15:07:11.946310   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
•I0726 15:07:12.548445   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:12.548494   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:12.552803   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:12.552847   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
E0726 15:07:12.557969   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-xdwtb\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-xdwtb" "namespace"="md-test"
E0726 15:07:12.947100   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
E0726 15:07:13.564486   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-dl57h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-dl57h" "namespace"="md-test"
I0726 15:07:13.947997   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7r9jp-mjgt6,ms-7r9jp-477sf" "indirect descendants count"=2
E0726 15:07:13.948567   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
E0726 15:07:14.564947   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-z6rf4\" for machine \"test-mhc-machine-jss2t\" in namespace \"test-mhc-qtkr7\": Cluster.cluster.x-k8s.io \"test-cluster-z6rf4\" not found" "controller"="machine" "name"="test-mhc-machine-jss2t" "namespace"="test-mhc-qtkr7"
E0726 15:07:14.958457   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
E0726 15:07:15.574493   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
E0726 15:07:15.959339   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
E0726 15:07:16.580069   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-xdwtb\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-xdwtb" "namespace"="md-test"
I0726 15:07:16.960041   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-bs8sn-74d45c49c5,md-bs8sn-cdfc6fd6c;Worker machines: md-bs8sn-74d45c49c5-xdwtb,md-bs8sn-74d45c49c5-dl57h,md-bs8sn-cdfc6fd6c-mbsvx,md-bs8sn-6657c7fddb-8tvkq,md-bs8sn-6657c7fddb-sn7pc,md-bs8sn-74d45c49c5-68s5b" "indirect descendants count"=8
E0726 15:07:16.960712   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
I0726 15:07:17.585891   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:17.585931   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:17.590406   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:17.590443   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
E0726 15:07:17.595007   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-dl57h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-dl57h" "namespace"="md-test"
E0726 15:07:17.961614   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
E0726 15:07:18.610766   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
E0726 15:07:18.962381   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
E0726 15:07:19.616272   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-xdwtb\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-xdwtb" "namespace"="md-test"
E0726 15:07:19.963182   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
E0726 15:07:20.620976   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-dl57h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-dl57h" "namespace"="md-test"
I0726 15:07:20.963780   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7r9jp-mjgt6,ms-7r9jp-477sf" "indirect descendants count"=2
E0726 15:07:20.964258   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
I0726 15:07:21.625564   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:21.625605   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:21.629018   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:21.629049   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:21.642774   10494 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-7bb7b" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0726 15:07:21.652654   10494 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-7bb7b" "namespace"="default" 
E0726 15:07:21.666857   10494 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-7bb7b" "namespace"="default"
E0726 15:07:21.964961   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
E0726 15:07:22.676350   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
E0726 15:07:22.965813   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
E0726 15:07:23.681792   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-xdwtb\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-xdwtb" "namespace"="md-test"
I0726 15:07:23.966531   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-bs8sn-cdfc6fd6c,md-bs8sn-74d45c49c5;Worker machines: md-bs8sn-74d45c49c5-xdwtb,md-bs8sn-74d45c49c5-dl57h,md-bs8sn-6657c7fddb-8tvkq,md-bs8sn-6657c7fddb-sn7pc,md-bs8sn-74d45c49c5-68s5b,md-bs8sn-cdfc6fd6c-mbsvx" "indirect descendants count"=8
E0726 15:07:23.967056   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
E0726 15:07:24.686876   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-74d45c49c5-dl57h\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-74d45c49c5-dl57h" "namespace"="md-test"
E0726 15:07:24.967714   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dg8t9: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dg8t9" "namespace"="default"
I0726 15:07:25.701275   10494 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-7bb7b" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0726 15:07:25.701527   10494 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-7bb7b" "namespace"="default" "noderef"="id-node-1"
E0726 15:07:25.724178   10494 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-7bb7b" "namespace"="default"
E0726 15:07:25.968495   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pzjpn: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pzjpn" "namespace"="default"
I0726 15:07:26.728615   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:26.728665   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-8tvkq" "namespace"="md-test" 
I0726 15:07:26.732172   10494 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
I0726 15:07:26.732204   10494 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-bs8sn-6657c7fddb-sn7pc" "namespace"="md-test" 
E0726 15:07:26.735660   10494 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-bs8sn-cdfc6fd6c-mbsvx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-bs8sn-cdfc6fd6c-mbsvx" "namespace"="md-test"
I0726 15:07:26.973032   10494 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-7r9jp-mjgt6,ms-7r9jp-477sf" "indirect descendants count"=2

------------------------------
• [SLOW TEST:15.073 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 27.063 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (27.06s)
PASS
Tearing down test suite
I0726 15:07:27.082199   10494 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0726 15:07:27.082217   10494 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0726 15:07:27.082245   10494 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0726 15:07:27.082266   10494 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:07:27.082281   10494 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:07:27.082296   10494 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
E0726 15:07:27.082449   10494 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0726 15:07:27.082491   10494 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-422753253/tls.crt: no such file or directory"  
I0726 15:07:27.082510   10494 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:07:27.118681   10494 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:45173/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1311&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:45173: connect: connection refused
E0726 15:07:27.118755   10494 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:45173/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1311&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:45173: connect: connection refused
E0726 15:07:27.118780   10494 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:45173/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1311&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:45173: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	84.391s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0726 15:06:16.339195   10927 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:06:16.350564   10927 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":{}}}
I0726 15:06:16.450970   10927 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0726 15:06:16.451041   10927 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0726 15:06:16.486994   10927 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0726 15:06:16.920292   10927 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0726 15:06:18.950250   10927 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-t6wmn/test-cluster"
•E0726 15:06:19.404368   10927 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-dlmps/test-cluster"
•E0726 15:06:19.939970   10927 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:41609/?timeout=50ms: dial tcp 127.0.0.1:41609: connect: connection refused"  "cluster"="cluster-cache-test-w5h56/test-cluster"
•I0726 15:06:20.152012   10927 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:06:20.204074   10927 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:45417/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:45417: connect: connection refused


Ran 5 of 5 Specs in 15.503 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.50s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	15.696s
?   	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
I0726 15:06:29.352779   11630 controller.go:133]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0726 15:06:29.354041   11630 controller.go:129]  "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
I0726 15:06:29.354638   11630 controller.go:139]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0726 15:06:29.354766   11630 controller.go:139]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
--- FAIL: TestReconcileClusterNoEndpoints (0.00s)
    controller_test.go:427: 
        Unexpected error:
            <*errors.withStack | 0xc0005e5b80>: {
                error: {
                    cause: {
                        error: {
                            cause: {
                                ErrStatus: {
                                    TypeMeta: {Kind: "", APIVersion: ""},
                                    ListMeta: {
                                        SelfLink: "",
                                        ResourceVersion: "",
... skipping 11 lines ...
                                        Causes: nil,
                                        RetryAfterSeconds: 0,
                                    },
                                    Code: 404,
                                },
                            },
                            msg: "failed to retrieve kubeconfig secret for Cluster test/foo",
                        },
                        stack: [0x1464401, 0x1734009, 0x172d97f, 0x174564c, 0x50fb29, 0x461751],
                    },
                    msg: "failed to create metadata only client",
                },
                stack: [0x172dc2b, 0x174564c, 0x50fb29, 0x461751],
            }
            failed to create metadata only client: failed to retrieve kubeconfig secret for Cluster test/foo: secrets "foo-kubeconfig" not found
        occurred
=== RUN   TestKubeadmControlPlaneReconciler_adoption
=== RUN   TestKubeadmControlPlaneReconciler_adoption/adopts_existing_Machines
I0726 15:06:29.358754   11630 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-q1dhpd" "kubeadmControlPlane"="kcp-foo-q1dhpd" "namespace"="test" 
=== RUN   TestKubeadmControlPlaneReconciler_adoption/adopts_v1alpha2_cluster_secrets
I0726 15:06:32.724229   11630 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-u864gy" "kubeadmControlPlane"="kcp-foo-u864gy" "namespace"="test" 
... skipping 4 lines ...
--- PASS: TestKubeadmControlPlaneReconciler_adoption (12.61s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/adopts_existing_Machines (3.37s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/adopts_v1alpha2_cluster_secrets (2.57s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/Deleted_KubeadmControlPlanes_don't_adopt_machines (3.27s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/refuses_to_adopt_Machines_that_are_more_than_one_version_old (3.40s)
=== RUN   TestReconcileInitializeControlPlane
--- FAIL: TestReconcileInitializeControlPlane (0.00s)
    controller_test.go:897: 
        Unexpected error:
            <*errors.withStack | 0xc0001c0620>: {
                error: {
                    cause: {
                        error: {
                            cause: {
                                ErrStatus: {
                                    TypeMeta: {Kind: "", APIVersion: ""},
                                    ListMeta: {
                                        SelfLink: "",
                                        ResourceVersion: "",
... skipping 11 lines ...
                                        Causes: nil,
                                        RetryAfterSeconds: 0,
                                    },
                                    Code: 404,
                                },
                            },
                            msg: "failed to retrieve kubeconfig secret for Cluster test/foo",
                        },
                        stack: [0x1464401, 0x1734009, 0x172d97f, 0x174838b, 0x50fb29, 0x461751],
                    },
                    msg: "failed to create metadata only client",
                },
                stack: [0x172dc2b, 0x174838b, 0x50fb29, 0x461751],
            }
            failed to create metadata only client: failed to retrieve kubeconfig secret for Cluster test/foo: secrets "foo-kubeconfig" not found
        occurred
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/updates_configmaps_and_deployments_successfully
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/returns_no_error_when_no_ClusterConfiguration_is_specified
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/should_not_return_an_error_when_there_is_no_CoreDNS_configmap
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/should_not_return_an_error_when_there_is_no_CoreDNS_deployment
... skipping 178 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
I0726 15:06:46.016452   11630 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
I0726 15:06:46.016577   11630 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: 1627311976
Will run 1 of 1 specs

E0726 15:06:46.058801   11630 controller.go:129]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-w76yyx\" not found" "kubeadmControlPlane"="kcp-foo-w76yyx" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.038 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.04s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0726 15:06:46.060190   11630 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-hvchaq" "kubeadmControlPlane"="kcp-foo-hvchaq" "namespace"="test" 
I0726 15:06:48.057686   11630 controller.go:348]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-hvchaq" "kubeadmControlPlane"="kcp-foo-hvchaq" "namespace"="test" "needRollout"=["kcp-foo-hvchaq-t5wth"]
I0726 15:06:48.057846   11630 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-hvchaq" "kubeadmControlPlane"="kcp-foo-hvchaq" "namespace"="test" "failures"="[machine kcp-foo-hvchaq-4wmmm does not have APIServerPodHealthy condition, machine kcp-foo-hvchaq-4wmmm does not have ControllerManagerPodHealthy condition, machine kcp-foo-hvchaq-4wmmm does not have SchedulerPodHealthy condition, machine kcp-foo-hvchaq-4wmmm does not have EtcdPodHealthy condition, machine kcp-foo-hvchaq-4wmmm does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (2.00s)
FAIL
I0726 15:06:48.058634   11630 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	32.222s
I0726 15:06:26.865273   11568 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:06:26.865385   11568 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:06:26.865417   11568 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:06:26.865439   11568 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:06:26.865534   11568 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
I0726 15:06:26.865555   11568 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1627311974
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: 1627311974
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
E0726 15:06:31.426530   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:06:39.749670   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:06:48.735642   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:06:59.865974   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:07:16.339299   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:07:29.347876   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:07:46.995344   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:08:07.918841   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:08:38.935431   11568 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:09:24.092686   11568 workload_cluster.go:325]  "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 71 lines ...
=== RUN   TestClusterStatus/returns_cluster_status
=== RUN   TestClusterStatus/returns_cluster_status_with_kubeadm_config
--- PASS: TestClusterStatus (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status_with_kubeadm_config (0.00s)
PASS
E0726 15:09:24.101366   11568 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:09:24.101410   11568 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-795925187/tls.crt: no such file or directory"  
I0726 15:09:24.101675   11568 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	189.491s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0726 15:06:38.264000   11882 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0726 15:06:38.364389   11882 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0726 15:06:38.364398   11882 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0726 15:06:38.464757   11882 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0726 15:06:38.464832   11882 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0726 15:06:38.560455   11882 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-wzlo90"} 
E0726 15:06:38.588504   11882 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"
•I0726 15:06:39.639917   11882 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-gskhcs"} 
E0726 15:06:39.670971   11882 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"
•E0726 15:06:40.737946   11882 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"
•E0726 15:06:41.763718   11882 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"
E0726 15:06:42.924469   11882 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"
E0726 15:06:43.974419   11882 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"
••I0726 15:06:44.990005   11882 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0726 15:06:44.990136   11882 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0726 15:06:44.990175   11882 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:06:44.990511   11882 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0726 15:06:44.990556   11882 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-432155237/tls.crt: no such file or directory"  
E0726 15:06:44.991557   11882 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"


Ran 5 of 5 Specs in 21.775 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (21.77s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	21.830s
?   	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
E0726 15:06:27.365454   12051 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 92 lines ...
•I0726 15:06:41.441148   12051 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0726 15:06:41.463122   12051 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0726 15:06:41.465282   12051 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0726 15:06:41.479876   12051 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}}}
I0726 15:06:41.508812   12051 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0726 15:06:41.557395   12051 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0726 15:06:41.560294   12051 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:06:41.560335   12051 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-553885501/tls.crt: no such file or directory"  
E0726 15:06:41.560356   12051 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:06:41.560375   12051 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-553885501/tls.crt: no such file or directory"  
I0726 15:06:41.560442   12051 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 14.148 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.15s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	14.353s
?   	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 200 lines ...
I0726 15:07:07.662099   15070 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"
I0726 15:07:07.662112   15070 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0726 15:07:07.662551   15070 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0726 15:07:07.663459   15070 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0726 15:07:07.663674   15070 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=37033
I0726 15:07:07.663861   15070 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••E0726 15:07:08.618982   15070 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:07:08.619099   15070 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-223318962/tls.crt: no such file or directory"  
E0726 15:07:08.619122   15070 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:07:08.619141   15070 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-223318962/tls.crt: no such file or directory"  
I0726 15:07:08.619164   15070 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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