This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-08-12 15:04
Elapsed4m49s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 774 lines ...
I0812 15:06:47.204170    8514 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0812 15:06:47.207640    8514 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0812 15:06:47.207992    8514 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=43927
I0812 15:06:47.208302    8514 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0812 15:06:48.147499    8514 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" 
•I0812 15:06:48.177331    8514 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0812 15:06:48.177804    8514 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0812 15:06:48.177852    8514 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-701845508/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 14.698 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.70s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	56.949s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1390 lines ...
I0812 15:06:30.120168   10576 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":{}}}
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0812 15:06:30.218197   10576 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"
2022/08/12 15:06:30 http: TLS handshake error from 127.0.0.1:53372: EOF
I0812 15:06:30.222470   10576 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
I0812 15:06:30.223242   10576 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
I0812 15:06:30.239868   10576 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_error_if_infrastructure_has_the_paused_annotation
... skipping 100 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0812 15:06:30.303458   10576 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
I0812 15:06:30.305861   10576 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"
E0812 15:06:30.306253   10576 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
I0812 15:06:30.306778   10576 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
... skipping 9 lines ...
I0812 15:06:30.320676   10576 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0812 15:06:30.320744   10576 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0812 15:06:30.320779   10576 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0812 15:06:30.320810   10576 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0812 15:06:30.326411   10576 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0812 15:06:30.796808   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0812 15:06:30.805166   10576 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0812 15:06:30.808462   10576 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-zn99r" "namespace"="test-machine-watches-vwjvs" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0812 15:06:30.808571   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0812 15:06:30.930795   10576 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-zn99r" "namespace"="test-machine-watches-vwjvs" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0812 15:06:30.930914   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0812 15:06:31.031546   10576 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-zn99r" "namespace"="test-machine-watches-vwjvs" "noderef"="node-1"
E0812 15:06:31.046878   10576 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0812 15:06:31.046953   10576 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0812 15:06:31.114234   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-zn99r\" in namespace \"test-machine-watches-vwjvs\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-zn99r" "namespace"="test-machine-watches-vwjvs"
E0812 15:06:32.120150   10576 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-zn99r\" in namespace \"test-machine-watches-vwjvs\", requeuing: requeue in 1s"  
E0812 15:06:32.128164   10576 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-zn99r\" in namespace \"test-machine-watches-vwjvs\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-zn99r\" in namespace \"test-machine-watches-vwjvs\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-zn99r" "namespace"="test-machine-watches-vwjvs"
--- PASS: TestWatches (1.90s)
=== 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
I0812 15:06:32.398289   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-hjmnj" "namespace"="test-machine-watches-vwjvs" "count"=1
I0812 15:06:32.398355   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-hjmnj" "namespace"="test-machine-watches-vwjvs" "descendants"="Worker machines: machine-created-zn99r" "indirect descendants count"=0
I0812 15:06:32.423554   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-hjmnj" "namespace"="test-machine-watches-vwjvs" "count"=1
I0812 15:06:32.423653   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-hjmnj" "namespace"="test-machine-watches-vwjvs" "descendants"="Worker machines: machine-created-zn99r" "indirect descendants count"=0
I0812 15:06:33.128810   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-hjmnj" "machine"="machine-created-zn99r" "namespace"="test-machine-watches-vwjvs" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"57cfa7b9-4beb-47d8-aead-4c6250a0f1df","apiVersion":"v1"}
E0812 15:06:33.251877   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-zn99r\" not found" "controller"="machine" "name"="machine-created-zn99r" "namespace"="test-machine-watches-vwjvs"
E0812 15:06:34.356108   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-wkp7r\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-m28cl\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-m28cl: secrets \"machine-reconcile-m28cl-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-wkp7r" "namespace"="default"
I0812 15:06:35.356948   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m28cl" "machine"="machine-created-wkp7r" "namespace"="default" "cause"="noderef is nil" "node"=null
I0812 15:06:35.447117   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m28cl" "machine"="machine-created-wkp7r" "namespace"="default" "cause"="noderef is nil" "node"=null
I0812 15:06:35.477862   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m28cl" "machine"="machine-created-wkp7r" "namespace"="default" "cause"="noderef is nil" "node"=null
E0812 15:06:35.528534   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-wkp7r\" not found" "controller"="machine" "name"="machine-created-wkp7r" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.33s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.33s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.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)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0812 15:06:35.564833   10576 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0812 15:06:35.567679   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-m28cl\" not found" "controller"="cluster" "name"="machine-reconcile-m28cl" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0812 15:06:35.575824   10576 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0812 15:06:35.586943   10576 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.04s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.01s)
... skipping 112 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
I0812 15:06:35.904113   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2g9b6" "namespace"="test-mhc-zcrvt" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0812 15:06:35.938496   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0812 15:06:35.939835   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-2wjff\" not found"  "cluster"="test-mhc-zcrvt/test-cluster-2wjff"
E0812 15:06:35.966485   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-2g9b6\" not found" "controller"="machinehealthcheck" "name"="test-mhc-2g9b6" "namespace"="test-mhc-zcrvt"
=== 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
I0812 15:06:36.967467   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2g9b6" "namespace"="test-mhc-zcrvt" 
I0812 15:06:36.967613   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7qqt4" "namespace"="test-mhc-t7cjl" 
I0812 15:06:36.967654   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wctjl" "namespace"="test-mhc-qpnl5" 
I0812 15:06:36.967705   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gfgmb" "namespace"="test-mhc-58lhg" 
I0812 15:06:37.023177   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0812 15:06:37.046391   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gfgmb" "namespace"="test-mhc-58lhg" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0812 15:06:37.076901   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gfgmb" "namespace"="test-mhc-58lhg" 
E0812 15:06:37.098973   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-58lhg/test-cluster-k6c67"
E0812 15:06:37.103171   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-k6c67\" not found" "controller"="cluster" "name"="test-cluster-k6c67" "namespace"="test-mhc-58lhg"
I0812 15:06:37.110786   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rc74n" "namespace"="test-mhc-582qh" 
I0812 15:06:37.131241   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0812 15:06:37.256855   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rc74n" "namespace"="test-mhc-582qh" 
E0812 15:06:37.325931   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-582qh/test-cluster-22p67"
I0812 15:06:37.345229   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rc74n" "namespace"="test-mhc-582qh" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0812 15:06:37.409953   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
inframachine created: test-mhc-machine-infra-lgfnt
I0812 15:06:37.446088   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-vln7z
node created: test-mhc-node-b4wwj
E0812 15:06:37.558993   10576 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-b4wwj"
E0812 15:06:37.560611   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-b4wwj, got []"  "node"="test-mhc-node-b4wwj"
I0812 15:06:37.560682   10576 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-cfdk6/test-mhc-2rnzn/test-mhc-machine-vln7z/"
I0812 15:06:37.560839   10576 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6" "noderef"="test-mhc-node-b4wwj"
E0812 15:06:37.566476   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-b4wwj, got []"  "node"="test-mhc-node-b4wwj"
E0812 15:06:37.566551   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-b4wwj, got []"  "node"="test-mhc-node-b4wwj"
E0812 15:06:37.568735   10576 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-b4wwj"
E0812 15:06:37.568784   10576 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-b4wwj"
inframachine created: test-mhc-machine-infra-k4kjv
machine created: test-mhc-machine-4vjjc
I0812 15:06:37.596787   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.617068   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.618262   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.619281   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
... skipping 45 lines ...
I0812 15:06:37.757035   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.759463   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.761807   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.768236   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.773425   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.776323   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.776860   10576 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-cfdk6/test-mhc-2rnzn/test-mhc-machine-4vjjc/"
E0812 15:06:37.800272   10576 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-nlcnh"
node created: test-mhc-node-nlcnh
E0812 15:06:37.800993   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nlcnh, got []"  "node"="test-mhc-node-nlcnh"
I0812 15:06:37.817793   10576 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6" "noderef"="test-mhc-node-nlcnh"
I0812 15:06:37.821424   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.843068   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
Cleaning up nodes, machines and infra machines.
I0812 15:06:37.854923   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.855457   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cfdk6/test-mhc-2rnzn/test-mhc-machine-vln7z/"
I0812 15:06:37.908332   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:37.909082   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cfdk6/test-mhc-2rnzn/test-mhc-machine-vln7z/"
I0812 15:06:37.913070   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cfdk6/test-mhc-2rnzn/test-mhc-machine-4vjjc/"
E0812 15:06:37.939093   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-cfdk6/test-cluster-q8cvz"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0812 15:06:37.958080   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-2rnzn\" not found" "controller"="machinehealthcheck" "name"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6"
inframachine created: test-mhc-machine-infra-cxqt6
machine created: test-mhc-machine-lrjgq
E0812 15:06:38.066220   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
E0812 15:06:38.120852   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-vwjvs/machine-reconcile-hjmnj"
I0812 15:06:38.958427   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2rnzn" "namespace"="test-mhc-cfdk6" 
I0812 15:06:38.958678   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:38.994554   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0812 15:06:39.084435   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:39.095653   10576 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-97dnb/test-mhc-j8cr9/test-mhc-machine-lrjgq/"
E0812 15:06:39.129376   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-x489z, got []"  "node"="test-mhc-node-x489z"
node created: test-mhc-node-x489z
inframachine created: test-mhc-machine-infra-9mlwz
I0812 15:06:39.188033   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
machine created: test-mhc-machine-dnngm
I0812 15:06:39.220825   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:39.233757   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
... skipping 246 lines ...
I0812 15:06:40.060174   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.062368   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.065296   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.067413   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.080816   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.083016   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
E0812 15:06:40.085078   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:06:40.087495   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.090286   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.092382   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.094588   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.097706   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:40.099883   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
... skipping 334 lines ...
I0812 15:06:41.103886   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.105017   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.108701   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.110856   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.132580   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.133968   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
E0812 15:06:41.136543   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:41.136748   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.138584   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.140155   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.143336   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.146041   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:41.148974   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
... skipping 303 lines ...
I0812 15:06:42.131732   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.141640   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.146714   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.149944   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.151504   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.154862   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
E0812 15:06:42.160496   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:06:42.162607   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.163396   10576 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-97dnb/test-mhc-j8cr9/test-mhc-machine-dnngm/"
I0812 15:06:42.180999   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.181502   10576 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-97dnb/test-mhc-j8cr9/test-mhc-machine-dnngm/"
node created: test-mhc-node-78bn7
E0812 15:06:42.247232   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-78bn7, got []"  "node"="test-mhc-node-78bn7"
I0812 15:06:42.256493   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
inframachine created: test-mhc-machine-infra-hb7q5
I0812 15:06:42.275847   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
machine created: test-mhc-machine-vsrbf
I0812 15:06:42.279809   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:42.287720   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
... skipping 221 lines ...
I0812 15:06:43.165149   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.168661   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.173036   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.177126   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.180561   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.181795   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
E0812 15:06:43.183015   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:43.183032   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.186575   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.188758   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.190675   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.192494   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:43.194346   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
... skipping 229 lines ...
I0812 15:06:44.224543   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.228002   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.231549   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.235435   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.241433   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.255369   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
E0812 15:06:44.257781   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:06:44.258879   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.262208   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.264142   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.266164   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.267796   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:44.269005   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
... skipping 201 lines ...
I0812 15:06:45.262882   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.265665   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.268656   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.270404   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.273168   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.274800   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.275365   10576 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-97dnb/test-mhc-j8cr9/test-mhc-machine-vsrbf/"
E0812 15:06:45.286969   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:45.293379   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.294230   10576 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-97dnb/test-mhc-j8cr9/test-mhc-machine-vsrbf/"
E0812 15:06:45.334837   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rvx79, got []"  "node"="test-mhc-node-rvx79"
node created: test-mhc-node-rvx79
Cleaning up nodes, machines and infra machines.
I0812 15:06:45.363308   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.363961   10576 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-97dnb/test-mhc-j8cr9/test-mhc-machine-vsrbf/test-mhc-node-rvx79"
Cleaning up nodes, machines and infra machines.
I0812 15:06:45.388970   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.389601   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-97dnb/test-mhc-j8cr9/test-mhc-machine-vsrbf/"
I0812 15:06:45.429431   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:45.431592   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-97dnb/test-mhc-j8cr9/test-mhc-machine-lrjgq/"
I0812 15:06:45.476767   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-97dnb/test-mhc-j8cr9/test-mhc-machine-dnngm/"
I0812 15:06:45.492919   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fs9bv" "namespace"="test-mhc-97dnb" "count"=2
I0812 15:06:45.493025   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fs9bv" "namespace"="test-mhc-97dnb" "descendants"="Worker machines: test-mhc-machine-lrjgq,test-mhc-machine-dnngm,test-mhc-machine-vsrbf" "indirect descendants count"=1
I0812 15:06:45.499718   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-fs9bv" "namespace"="test-mhc-97dnb" "count"=2
I0812 15:06:45.499791   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-fs9bv" "namespace"="test-mhc-97dnb" "descendants"="Worker machines: test-mhc-machine-vsrbf,test-mhc-machine-lrjgq,test-mhc-machine-dnngm" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0812 15:06:45.518993   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-97dnb/test-mhc-j8cr9/test-mhc-machine-vsrbf/"
E0812 15:06:45.523961   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-j8cr9\" not found" "controller"="machinehealthcheck" "name"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb"
inframachine created: test-mhc-machine-infra-twlfm
machine created: test-mhc-machine-nmpsc
I0812 15:06:46.287507   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fs9bv" "machine"="test-mhc-machine-dnngm" "namespace"="test-mhc-97dnb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-78bn7"}
E0812 15:06:46.343047   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dnngm\" not found" "controller"="machine" "name"="test-mhc-machine-dnngm" "namespace"="test-mhc-97dnb"
I0812 15:06:46.524312   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j8cr9" "namespace"="test-mhc-97dnb" 
I0812 15:06:46.524434   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:46.551416   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0812 15:06:46.682839   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:46.688082   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:46.713841   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:46.754964   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:46.836099   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:46.997447   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:47.318657   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:47.343507   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:06:47.959876   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:48.344105   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fs9bv" "machine"="test-mhc-machine-vsrbf" "namespace"="test-mhc-97dnb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-rvx79"}
E0812 15:06:48.412470   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vsrbf\" not found" "controller"="machine" "name"="test-mhc-machine-vsrbf" "namespace"="test-mhc-97dnb"
I0812 15:06:49.241224   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:49.413218   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:50.413894   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-fs9bv" "machine"="test-mhc-machine-lrjgq" "namespace"="test-mhc-97dnb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-x489z"}
E0812 15:06:50.498789   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lrjgq\" not found" "controller"="machine" "name"="test-mhc-machine-lrjgq" "namespace"="test-mhc-97dnb"
E0812 15:06:50.529837   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-97dnb/test-cluster-fs9bv"
I0812 15:06:51.510861   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:51.526779   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:06:51.527640   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:51.561236   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:51.624182   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wdr44, got []"  "node"="test-mhc-node-wdr44"
node created: test-mhc-node-wdr44
I0812 15:06:51.636682   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
inframachine created: test-mhc-machine-infra-2v6qp
machine created: test-mhc-machine-dv5x5
I0812 15:06:51.714498   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:51.737337   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:51.738891   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:51.743085   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:51.784413   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:51.870113   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:52.031638   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:52.354709   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:52.527307   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:53.002233   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:53.543168   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:53.551500   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:53.564178   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:53.586778   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:53.593813   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:53.598947   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:53.600152   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:06:53.625905   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
node created: test-mhc-node-dpmm4
E0812 15:06:53.697406   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-dpmm4, got []"  "node"="test-mhc-node-dpmm4"
I0812 15:06:53.710844   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
inframachine created: test-mhc-machine-infra-bvh4j
I0812 15:06:53.728443   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:53.733516   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
machine created: test-mhc-machine-j6q7l
I0812 15:06:53.749109   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:54.284207   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:54.600678   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:55.615253   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.634181   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.645851   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.670576   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.681003   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.698593   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:55.705449   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:06:55.708674   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.735563   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
E0812 15:06:55.747253   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ptqvl, got []"  "node"="test-mhc-node-ptqvl"
node created: test-mhc-node-ptqvl
I0812 15:06:55.756340   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
Cleaning up nodes, machines and infra machines.
I0812 15:06:55.770888   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.786751   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.814600   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
... skipping 2 lines ...
I0812 15:06:55.829464   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:55.856687   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qmhbr" "namespace"="test-mhc-5vwbv" "count"=2
I0812 15:06:55.856782   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qmhbr" "namespace"="test-mhc-5vwbv" "descendants"="Worker machines: test-mhc-machine-nmpsc,test-mhc-machine-dv5x5,test-mhc-machine-j6q7l" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
I0812 15:06:55.862992   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qmhbr" "namespace"="test-mhc-5vwbv" "count"=2
I0812 15:06:55.863045   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qmhbr" "namespace"="test-mhc-5vwbv" "descendants"="Worker machines: test-mhc-machine-nmpsc,test-mhc-machine-dv5x5,test-mhc-machine-j6q7l" "indirect descendants count"=1
E0812 15:06:55.866155   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-8gs5t\" not found" "controller"="machinehealthcheck" "name"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv"
inframachine created: test-mhc-machine-infra-hcqtz
machine created: test-mhc-machine-x7qzw
E0812 15:06:56.706074   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:06:56.869083   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gs5t" "namespace"="test-mhc-5vwbv" 
I0812 15:06:56.869206   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:06:56.917588   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0812 15:06:56.955707   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:06:57.706841   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qmhbr" "machine"="test-mhc-machine-nmpsc" "namespace"="test-mhc-5vwbv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wdr44"}
E0812 15:06:57.768448   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nmpsc\" not found" "controller"="machine" "name"="test-mhc-machine-nmpsc" "namespace"="test-mhc-5vwbv"
I0812 15:06:58.769077   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qmhbr" "machine"="test-mhc-machine-dv5x5" "namespace"="test-mhc-5vwbv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-dpmm4"}
E0812 15:06:58.827935   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dv5x5\" not found" "controller"="machine" "name"="test-mhc-machine-dv5x5" "namespace"="test-mhc-5vwbv"
I0812 15:06:59.828548   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qmhbr" "machine"="test-mhc-machine-j6q7l" "namespace"="test-mhc-5vwbv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ptqvl"}
E0812 15:06:59.898796   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j6q7l\" not found" "controller"="machine" "name"="test-mhc-machine-j6q7l" "namespace"="test-mhc-5vwbv"
E0812 15:07:00.879776   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5vwbv/test-cluster-qmhbr"
I0812 15:07:00.910733   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:00.915881   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
E0812 15:07:00.916044   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
node created: test-mhc-node-rnqpd
E0812 15:07:00.978121   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rnqpd, got []"  "node"="test-mhc-node-rnqpd"
I0812 15:07:00.987476   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
inframachine created: test-mhc-machine-infra-82zhj
I0812 15:07:01.007726   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:01.016169   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
machine created: test-mhc-machine-nxgpz
I0812 15:07:01.024473   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
E0812 15:07:01.917016   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:07:02.938030   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:02.964775   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:02.990289   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:02.998699   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:03.015780   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
E0812 15:07:03.025048   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:07:03.025502   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
node created: test-mhc-node-wvqd5
E0812 15:07:03.032644   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wvqd5, got []"  "node"="test-mhc-node-wvqd5"
I0812 15:07:03.074551   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
inframachine created: test-mhc-machine-infra-d4rt8
I0812 15:07:03.097533   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
machine created: test-mhc-machine-qtzdb
I0812 15:07:03.104383   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:03.118318   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
... skipping 2 lines ...
I0812 15:07:04.080833   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:04.094093   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:04.109903   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:04.116871   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:04.128281   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:04.140900   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
E0812 15:07:04.141298   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
Cleaning up nodes, machines and infra machines.
I0812 15:07:04.211552   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
Cleaning up nodes, machines and infra machines.
I0812 15:07:04.230273   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:04.230922   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kqwzd/test-mhc-rx5gd/test-mhc-machine-x7qzw/"
I0812 15:07:04.262896   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:04.263600   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kqwzd/test-mhc-rx5gd/test-mhc-machine-x7qzw/"
I0812 15:07:04.264083   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kqwzd/test-mhc-rx5gd/test-mhc-machine-nxgpz/"
I0812 15:07:04.290671   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-64znl" "namespace"="test-mhc-kqwzd" "count"=2
I0812 15:07:04.290769   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-64znl" "namespace"="test-mhc-kqwzd" "descendants"="Worker machines: test-mhc-machine-x7qzw,test-mhc-machine-nxgpz,test-mhc-machine-qtzdb" "indirect descendants count"=1
I0812 15:07:04.295137   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-64znl" "namespace"="test-mhc-kqwzd" "count"=2
I0812 15:07:04.295212   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-64znl" "namespace"="test-mhc-kqwzd" "descendants"="Worker machines: test-mhc-machine-x7qzw,test-mhc-machine-nxgpz,test-mhc-machine-qtzdb" "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
inframachine created: test-mhc-machine-infra-tbc7r
machine created: test-mhc-machine-dc488
E0812 15:07:04.403130   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-rx5gd\" not found" "controller"="machinehealthcheck" "name"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd"
I0812 15:07:05.142294   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-64znl" "machine"="test-mhc-machine-x7qzw" "namespace"="test-mhc-kqwzd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-rnqpd"}
E0812 15:07:05.232176   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-x7qzw\" not found" "controller"="machine" "name"="test-mhc-machine-x7qzw" "namespace"="test-mhc-kqwzd"
I0812 15:07:05.403506   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:05.424475   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0812 15:07:05.545878   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rx5gd" "namespace"="test-mhc-kqwzd" 
I0812 15:07:05.545952   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:05.547022   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:05.548821   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
... skipping 343 lines ...
I0812 15:07:06.399669   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.401886   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.403682   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.405501   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.416160   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.417990   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
E0812 15:07:06.419073   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nxgpz\" not found" "controller"="machine" "name"="test-mhc-machine-nxgpz" "namespace"="test-mhc-kqwzd"
I0812 15:07:06.419863   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.421776   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.424211   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.426387   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.430284   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:06.434220   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
... skipping 390 lines ...
I0812 15:07:07.477938   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.480074   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.482248   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.484491   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.486859   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.489399   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
E0812 15:07:07.491521   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qtzdb\" not found" "controller"="machine" "name"="test-mhc-machine-qtzdb" "namespace"="test-mhc-kqwzd"
I0812 15:07:07.492003   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.495414   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.497490   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.500349   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.502461   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:07.504352   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
... skipping 378 lines ...
I0812 15:07:08.500053   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.503912   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.505929   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.507768   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.508813   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.511083   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.512507   10576 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-7p7j8/test-mhc-jnwgk/test-mhc-machine-dc488/"
E0812 15:07:08.521446   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:07:08.532170   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.532544   10576 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-7p7j8/test-mhc-jnwgk/test-mhc-machine-dc488/"
node created: test-mhc-node-v8g7c
E0812 15:07:08.599992   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v8g7c, got []"  "node"="test-mhc-node-v8g7c"
E0812 15:07:08.599992   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v8g7c, got []"  "node"="test-mhc-node-v8g7c"
I0812 15:07:08.610370   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.630518   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.632222   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.640984   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.641280   10576 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-7p7j8/test-mhc-jnwgk/test-mhc-machine-dc488/test-mhc-node-v8g7c"
I0812 15:07:08.664927   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.665698   10576 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-7p7j8/test-mhc-jnwgk/test-mhc-machine-dc488/test-mhc-node-v8g7c"
I0812 15:07:08.666949   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.667740   10576 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-7p7j8/test-mhc-jnwgk/test-mhc-machine-dc488/test-mhc-node-v8g7c"
Cleaning up nodes, machines and infra machines.
I0812 15:07:08.677006   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.677439   10576 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-7p7j8/test-mhc-jnwgk/test-mhc-machine-dc488/test-mhc-node-v8g7c"
I0812 15:07:08.678482   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.678808   10576 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7p7j8/test-mhc-jnwgk/test-mhc-machine-dc488/"
I0812 15:07:08.716239   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-m4jp7" "namespace"="test-mhc-7p7j8" "descendants"="Worker machines: test-mhc-machine-dc488" "indirect descendants count"=1
I0812 15:07:08.721918   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-m4jp7" "namespace"="test-mhc-7p7j8" "descendants"="Worker machines: test-mhc-machine-dc488" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0812 15:07:08.845251   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jnwgk" "namespace"="test-mhc-7p7j8" 
I0812 15:07:08.851878   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" "creating"=1 "need"=1
I0812 15:07:08.851936   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
I0812 15:07:08.877585   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-cv26g-688v6\"" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
I0812 15:07:08.937868   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:08.985510   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0812 15:07:08.992309   10576 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
I0812 15:07:09.118224   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:09.124945   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
E0812 15:07:09.312294   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kqwzd/test-cluster-64znl"
E0812 15:07:09.522064   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:07:10.118480   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:10.522709   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m4jp7" "machine"="test-mhc-machine-dc488" "namespace"="test-mhc-7p7j8" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-v8g7c"}
E0812 15:07:10.578324   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dc488\" not found" "controller"="machine" "name"="test-mhc-machine-dc488" "namespace"="test-mhc-7p7j8"
I0812 15:07:11.119579   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:11.587818   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:11.588594   10576 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
I0812 15:07:11.595457   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:11.595496   10576 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
I0812 15:07:11.614981   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
... skipping 5 lines ...
I0812 15:07:11.634636   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:11.640110   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:11.640158   10576 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:11.656698   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:11.656749   10576 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:12.120694   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:12.121145   10576 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-85466/test-mhc-nb5b7/mhc-ms-cv26g-688v6/"
I0812 15:07:12.130437   10576 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
I0812 15:07:12.137948   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:12.138003   10576 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:12.143177   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:12.144728   10576 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-85466/test-mhc-nb5b7/mhc-ms-cv26g-688v6/"
I0812 15:07:12.146336   10576 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
I0812 15:07:12.147608   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:12.148086   10576 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-85466/test-mhc-nb5b7/mhc-ms-cv26g-688v6/"
I0812 15:07:12.172107   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:12.172180   10576 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" 
I0812 15:07:12.229704   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-g69dg" "namespace"="test-mhc-85466" "count"=1
I0812 15:07:12.229778   10576 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-g69dg" "namespace"="test-mhc-85466" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-cv26g"
I0812 15:07:12.233876   10576 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" "machine"="mhc-ms-cv26g-688v6"
I0812 15:07:12.244865   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-g69dg" "namespace"="test-mhc-85466" "descendants"="Machine sets: mhc-ms-cv26g;Worker machines: mhc-ms-cv26g-688v6" "indirect descendants count"=1
I0812 15:07:12.245186   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb5b7" "namespace"="test-mhc-85466" 
I0812 15:07:12.248994   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-g69dg" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" "cause"="cluster is being deleted" "node"=null
I0812 15:07:12.254736   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-g69dg" "namespace"="test-mhc-85466" "descendants"="Worker machines: mhc-ms-cv26g-688v6" "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
E0812 15:07:12.276762   10576 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-cv26g\" not found" "machineset"="mhc-ms-cv26g" "namespace"="test-mhc-85466" 
E0812 15:07:12.276975   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-cv26g\" not found" "controller"="machineset" "name"="mhc-ms-cv26g" "namespace"="test-mhc-85466"
I0812 15:07:12.362048   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
inframachine created: test-mhc-machine-infra-cmjg5
I0812 15:07:12.381921   10576 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-jhdvk
I0812 15:07:12.503761   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-g69dg" "machine"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466" "cause"="cluster is being deleted" "node"=null
E0812 15:07:12.546906   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-cv26g-688v6\" not found" "controller"="machine" "name"="mhc-ms-cv26g-688v6" "namespace"="test-mhc-85466"
I0812 15:07:12.553084   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
node created: test-mhc-node-q4ljt
E0812 15:07:12.603244   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q4ljt, got []"  "node"="test-mhc-node-q4ljt"
E0812 15:07:12.603328   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q4ljt, got []"  "node"="test-mhc-node-q4ljt"
E0812 15:07:12.603391   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q4ljt, got []"  "node"="test-mhc-node-q4ljt"
I0812 15:07:12.622722   10576 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-jhdvk" "target"="test-mhc-kpqcb/test-mhc-g4vlj/test-mhc-machine-jhdvk/"
I0812 15:07:12.640605   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
I0812 15:07:12.691076   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
I0812 15:07:12.705733   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
I0812 15:07:12.715003   10576 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-jhdvk" "target"="test-mhc-kpqcb/test-mhc-g4vlj/test-mhc-machine-jhdvk/test-mhc-node-q4ljt"
I0812 15:07:12.761859   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
Cleaning up nodes, machines and infra machines.
I0812 15:07:12.786650   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
I0812 15:07:12.792988   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
I0812 15:07:12.796831   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g4vlj" "namespace"="test-mhc-kpqcb" 
I0812 15:07:12.802150   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c88l2" "namespace"="test-mhc-kpqcb" "descendants"="Worker machines: test-mhc-machine-jhdvk" "indirect descendants count"=1
... skipping 186 lines ...
I0812 15:07:13.614973   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.620317   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.622231   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.633812   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.646230   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.650682   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
E0812 15:07:13.651163   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jhdvk\" not found" "controller"="machine" "name"="test-mhc-machine-jhdvk" "namespace"="test-mhc-kpqcb"
I0812 15:07:13.653243   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.655311   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.657184   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.659177   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.661131   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.663867   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
... skipping 18 lines ...
I0812 15:07:13.716605   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.719746   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.727795   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.730440   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.735887   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.737909   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
E0812 15:07:13.746354   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7p7j8/test-cluster-m4jp7"
I0812 15:07:13.747045   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.749364   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.751949   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.754693   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.758564   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:13.761370   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
... skipping 369 lines ...
I0812 15:07:14.646472   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.648675   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.654010   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.656561   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.660347   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.670480   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
E0812 15:07:14.674251   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
I0812 15:07:14.686171   10576 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-sfbg8" "target"="test-mhc-rqhcw/test-mhc-q6pqx/test-mhc-machine-sfbg8/"
I0812 15:07:14.710077   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
node created: test-mhc-node-2bmz5
E0812 15:07:14.721426   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2bmz5, got []"  "node"="test-mhc-node-2bmz5"
E0812 15:07:14.721800   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2bmz5, got []"  "node"="test-mhc-node-2bmz5"
E0812 15:07:14.722205   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2bmz5, got []"  "node"="test-mhc-node-2bmz5"
I0812 15:07:14.730662   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.773705   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.787024   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.792030   10576 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-sfbg8" "target"="test-mhc-rqhcw/test-mhc-q6pqx/test-mhc-machine-sfbg8/test-mhc-node-2bmz5"
I0812 15:07:14.819048   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.837413   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.865052   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
Cleaning up nodes, machines and infra machines.
I0812 15:07:14.877744   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:14.882827   10576 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-sfbg8" "target"="test-mhc-rqhcw/test-mhc-q6pqx/test-mhc-machine-sfbg8/"
I0812 15:07:14.892052   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-72vvd" "namespace"="test-mhc-rqhcw" "descendants"="Worker machines: test-mhc-machine-sfbg8" "indirect descendants count"=1
I0812 15:07:14.901236   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-72vvd" "namespace"="test-mhc-rqhcw" "descendants"="Worker machines: test-mhc-machine-sfbg8" "indirect descendants count"=1
E0812 15:07:14.906085   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-q6pqx\" not found" "controller"="machinehealthcheck" "name"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw"
--- PASS: TestMachineHealthCheck_Reconcile (39.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.16s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.14s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (0.96s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.27s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.55s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.09s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0812 15:07:14.908567   10576 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
E0812 15:07:14.910814   10576 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
E0812 15:07:14.915411   10576 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0812 15:07:14.916476   10576 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
E0812 15:07:14.917347   10576 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.01s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.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
I0812 15:07:14.921230   10576 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0812 15:07:14.922212   10576 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0812 15:07:14.924787   10576 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.01s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0812 15:07:14.939721   10576 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
E0812 15:07:14.943154   10576 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 ...
I0812 15:07:15.150601   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-hjzx2-4kw87\"" "machineset"="ms-hjzx2" "namespace"="ms-test" 
I0812 15:07:15.150683   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-hjzx2" "namespace"="ms-test" 
I0812 15:07:15.185837   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-hjzx2-xfss9\"" "machineset"="ms-hjzx2" "namespace"="ms-test" 
I0812 15:07:15.303432   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-hjzx2" "namespace"="ms-test" "creating"=1 "need"=2
I0812 15:07:15.303469   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-hjzx2" "namespace"="ms-test" 
I0812 15:07:15.319823   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-hjzx2-rs5gq\"" "machineset"="ms-hjzx2" "namespace"="ms-test" 
E0812 15:07:15.430255   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.430552   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.430749   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.533534   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.533589   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.533941   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.533989   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.534148   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.534176   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-rs5gq-r8dnc, got []"  "node"="ms-hjzx2-rs5gq-r8dnc"
E0812 15:07:15.575751   10576 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-hjzx2-rs5gq-r8dnc for machine ms-test/ms-hjzx2-rs5gq: the cache is not started, can not read objects" "machineset"="ms-hjzx2" "namespace"="ms-test" 
E0812 15:07:15.585637   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.585669   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.585640   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.591591   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.591610   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.591647   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.591647   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.591655   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.591690   10576 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-hjzx2-xfss9-bsb42, got []"  "node"="ms-hjzx2-xfss9-bsb42"
E0812 15:07:15.674922   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
I0812 15:07:15.740825   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-hjzx2-rs5gq,ms-hjzx2-xfss9" "indirect descendants count"=2
I0812 15:07:15.746742   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-hjzx2-rs5gq,ms-hjzx2-xfss9" "indirect descendants count"=2
••E0812 15:07:15.893920   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-2gm77\" not found" "controller"="cluster" "name"="test1-2gm77" "namespace"="default"
I0812 15:07:15.906457   10576 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q6pqx" "namespace"="test-mhc-rqhcw" 
I0812 15:07:16.675726   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-72vvd" "machine"="test-mhc-machine-sfbg8" "namespace"="test-mhc-rqhcw" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2bmz5"}
E0812 15:07:16.736725   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-sfbg8\" not found" "controller"="machine" "name"="test-mhc-machine-sfbg8" "namespace"="test-mhc-rqhcw"
•I0812 15:07:17.041803   10576 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-b4spz" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0812 15:07:17.176581   10576 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-b4spz" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0812 15:07:17.185783   10576 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-b4spz" "namespace"="default"
E0812 15:07:18.211643   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"
•E0812 15:07:19.238275   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-85466/test-cluster-g69dg"
E0812 15:07:19.267330   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kpqcb/test-cluster-c88l2"
E0812 15:07:19.290550   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-fqnsp\" not found" "controller"="cluster" "name"="test3-fqnsp" "namespace"="default"
E0812 15:07:20.291439   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"
E0812 15:07:21.317882   10576 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rqhcw/test-cluster-72vvd"
E0812 15:07:21.318647   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"
•I0812 15:07:22.319219   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-hjzx2-rs5gq,ms-hjzx2-xfss9" "indirect descendants count"=2
E0812 15:07:22.324828   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-69sfg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-69sfg" "namespace"="default"
E0812 15:07:23.325814   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"
E0812 15:07:24.338535   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-69sfg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-69sfg" "namespace"="default"
•E0812 15:07:24.914687   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-vln7z\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-vln7z" "namespace"="test-mhc-cfdk6"
E0812 15:07:25.339299   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"
E0812 15:07:25.915259   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-q8cvz\" for machine \"test-mhc-machine-4vjjc\" in namespace \"test-mhc-cfdk6\": Cluster.cluster.x-k8s.io \"test-cluster-q8cvz\" not found" "controller"="machine" "name"="test-mhc-machine-4vjjc" "namespace"="test-mhc-cfdk6"
E0812 15:07:26.340200   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-69sfg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-69sfg" "namespace"="default"
E0812 15:07:27.353475   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"
I0812 15:07:27.419045   10576 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-qq685" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0812 15:07:27.434726   10576 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-qq685" "namespace"="default" 
E0812 15:07:27.466569   10576 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-qq685" "namespace"="default"
E0812 15:07:28.354436   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-69sfg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-69sfg" "namespace"="default"
I0812 15:07:28.494089   10576 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-qq685" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0812 15:07:28.495218   10576 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-qq685" "namespace"="default" "noderef"="id-node-1"
E0812 15:07:28.518174   10576 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-qq685" "namespace"="default"
I0812 15:07:29.355027   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-hjzx2-rs5gq,ms-hjzx2-xfss9" "indirect descendants count"=2
E0812 15:07:29.360216   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"

------------------------------
• [SLOW TEST:5.046 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 21 lines ...
I0812 15:07:29.415642   10576 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"
•I0812 15:07:29.417557   10576 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"
I0812 15:07:29.418569   10576 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"
I0812 15:07:29.419212   10576 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0812 15:07:29.419239   10576 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0812 15:07:29.419999   10576 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0812 15:07:29.421804   10576 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" 
•I0812 15:07:29.519155   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-8n7gh" "machine"="test6-qq685" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"636d732a-ca86-4265-8793-6c6122a7d951","apiVersion":"v1"}
I0812 15:07:29.525770   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0812 15:07:29.525876   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:29.539958   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-tc8mc-6657c7fddb-wzxjd\"" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:29.540025   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
E0812 15:07:29.547979   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-qq685\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-qq685" "namespace"="default"
I0812 15:07:29.554059   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-tc8mc-6657c7fddb-mczxz\"" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
E0812 15:07:29.571753   10576 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-tc8mc-6657c7fddb\" not found" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
E0812 15:07:29.571875   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-tc8mc-6657c7fddb\" not found" "controller"="machineset" "name"="md-tc8mc-6657c7fddb" "namespace"="md-test"
E0812 15:07:30.361041   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-69sfg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-69sfg" "namespace"="default"
I0812 15:07:30.571948   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-8n7gh" "machine"="test6-qq685" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"636d732a-ca86-4265-8793-6c6122a7d951","apiVersion":"v1"}
E0812 15:07:30.572940   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-qq685\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-qq685" "namespace"="default"
I0812 15:07:30.576611   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "creating"=3 "need"=3
I0812 15:07:30.576656   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:30.586760   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 3 with name \"md-tc8mc-6657c7fddb-bqcwb\"" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:30.586921   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:30.597863   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 3 with name \"md-tc8mc-6657c7fddb-r6wsd\"" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:30.597921   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 3 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:30.613418   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 3 of 3 with name \"md-tc8mc-6657c7fddb-nbhj9\"" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" 
I0812 15:07:30.731659   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0812 15:07:30.731730   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
I0812 15:07:30.751541   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tc8mc-cdfc6fd6c-nhhtt\"" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
E0812 15:07:30.972765   10576 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-tc8mc-cdfc6fd6c-nhhtt-8mmp8 for machine md-test/md-tc8mc-cdfc6fd6c-nhhtt: the cache is not started, can not read objects" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
I0812 15:07:31.021022   10576 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0812 15:07:31.021347   10576 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0812 15:07:31.028651   10576 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "machine"="md-tc8mc-6657c7fddb-bqcwb"
I0812 15:07:31.060033   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0812 15:07:31.060094   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
I0812 15:07:31.091310   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tc8mc-cdfc6fd6c-5w9wc\"" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
I0812 15:07:31.335875   10576 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0812 15:07:31.335925   10576 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0812 15:07:31.341306   10576 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "machine"="md-tc8mc-6657c7fddb-r6wsd"
I0812 15:07:31.361746   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-8n7gh" "namespace"="default" "count"=1
I0812 15:07:31.361818   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-8n7gh" "namespace"="default" "descendants"="Control plane machines: test6-qq685" "indirect descendants count"=0
E0812 15:07:31.378085   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-b4spz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-b4spz" "namespace"="default"
I0812 15:07:31.453878   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0812 15:07:31.454036   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
I0812 15:07:31.470828   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tc8mc-cdfc6fd6c-5chsq\"" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
I0812 15:07:31.625969   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tc8mc-6657c7fddb-wzxjd" "namespace"="md-test" 
I0812 15:07:31.626026   10576 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tc8mc-6657c7fddb-wzxjd" "namespace"="md-test" 
I0812 15:07:31.644258   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-8n7gh" "machine"="test6-qq685" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"636d732a-ca86-4265-8793-6c6122a7d951","apiVersion":"v1"}
E0812 15:07:31.646231   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-qq685\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-qq685" "namespace"="default"
I0812 15:07:31.695284   10576 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0812 15:07:31.695359   10576 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0812 15:07:31.712222   10576 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tc8mc-6657c7fddb" "namespace"="md-test" "machine"="md-tc8mc-6657c7fddb-nbhj9"
E0812 15:07:31.846383   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Operation cannot be fulfilled on machinedeployments.cluster.x-k8s.io \"md-tc8mc\": the object has been modified; please apply your changes to the latest version and try again" "controller"="machinedeployment" "name"="md-tc8mc" "namespace"="md-test"
E0812 15:07:32.378950   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-69sfg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-69sfg" "namespace"="default"
I0812 15:07:32.746523   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tc8mc-6657c7fddb-mczxz" "namespace"="md-test" 
I0812 15:07:32.747150   10576 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tc8mc-6657c7fddb-mczxz" "namespace"="md-test" 
I0812 15:07:32.776706   10576 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tc8mc-6657c7fddb-wzxjd" "namespace"="md-test" 
I0812 15:07:32.776778   10576 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tc8mc-6657c7fddb-wzxjd" "namespace"="md-test" 
I0812 15:07:32.777699   10576 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-8n7gh" "machine"="test6-qq685" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"636d732a-ca86-4265-8793-6c6122a7d951","apiVersion":"v1"}
E0812 15:07:32.778565   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-qq685\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-qq685" "namespace"="default"
I0812 15:07:32.869140   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tc8mc-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0812 15:07:32.869202   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-tc8mc-74d45c49c5" "namespace"="md-test" 
I0812 15:07:32.886970   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tc8mc-74d45c49c5-cc8hr\"" "machineset"="md-tc8mc-74d45c49c5" "namespace"="md-test" 
I0812 15:07:33.098013   10576 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0812 15:07:33.098061   10576 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0812 15:07:33.103997   10576 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "machine"="md-tc8mc-cdfc6fd6c-5w9wc"
... skipping 2 lines ...
I0812 15:07:33.148769   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tc8mc-74d45c49c5-8rx89\"" "machineset"="md-tc8mc-74d45c49c5" "namespace"="md-test" 
I0812 15:07:33.342238   10576 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0812 15:07:33.342313   10576 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0812 15:07:33.347126   10576 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "machine"="md-tc8mc-cdfc6fd6c-5chsq"
I0812 15:07:33.379624   10576 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-8n7gh" "namespace"="default" "count"=1
I0812 15:07:33.379780   10576 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-8n7gh" "namespace"="default" "descendants"="Control plane machines: test6-qq685" "indirect descendants count"=0
E0812 15:07:33.380579   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-69sfg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-69sfg" "namespace"="default"
I0812 15:07:33.463781   10576 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tc8mc-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0812 15:07:33.463846   10576 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-tc8mc-74d45c49c5" "namespace"="md-test" 
I0812 15:07:33.485106   10576 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tc8mc-74d45c49c5-lv594\"" "machineset"="md-tc8mc-74d45c49c5" "namespace"="md-test" 
E0812 15:07:33.601444   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-tc8mc\" not found" "controller"="machinedeployment" "name"="md-tc8mc" "namespace"="md-test"
•

Ran 16 of 16 Specs in 18.657 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (18.66s)
PASS
Tearing down test suite
I0812 15:07:33.603718   10576 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0812 15:07:33.603763   10576 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0812 15:07:33.603824   10576 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0812 15:07:33.603857   10576 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0812 15:07:33.603894   10576 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0812 15:07:33.603910   10576 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0812 15:07:33.603925   10576 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
E0812 15:07:33.604265   10576 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0812 15:07:33.604366   10576 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-938510307/tls.crt: no such file or directory"  
I0812 15:07:33.606624   10576 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0812 15:07:33.606673   10576 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
E0812 15:07:33.607105   10576 machineset_controller.go:400] controllers/MachineSet "msg"="Unable to delete Machine" "error"="Delete http://127.0.0.1:42699/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machines/md-tc8mc-cdfc6fd6c-nhhtt: dial tcp 127.0.0.1:42699: connect: connection refused" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" "machine"="md-tc8mc-cdfc6fd6c-nhhtt"
E0812 15:07:33.607563   10576 event.go:272] Unable to write event: 'Post http://127.0.0.1:42699/api/v1/namespaces/md-test/events: dial tcp 127.0.0.1:42699: connect: connection refused' (may retry after sleeping)
E0812 15:07:33.608057   10576 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to sync machines: Delete http://127.0.0.1:42699/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machines/md-tc8mc-cdfc6fd6c-nhhtt: dial tcp 127.0.0.1:42699: connect: connection refused. failed to patch MachineSet's Status: Patch http://127.0.0.1:42699/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-tc8mc-cdfc6fd6c/status: dial tcp 127.0.0.1:42699: connect: connection refused" "machineset"="md-tc8mc-cdfc6fd6c" "namespace"="md-test" 
E0812 15:07:33.608310   10576 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to sync machines: Delete http://127.0.0.1:42699/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machines/md-tc8mc-cdfc6fd6c-nhhtt: dial tcp 127.0.0.1:42699: connect: connection refused. failed to patch MachineSet's Status: Patch http://127.0.0.1:42699/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-tc8mc-cdfc6fd6c/status: dial tcp 127.0.0.1:42699: connect: connection refused" "controller"="machineset" "name"="md-tc8mc-cdfc6fd6c" "namespace"="md-test"
E0812 15:07:33.645992   10576 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:42699/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1213&timeout=10s&timeoutSeconds=579&watch=true: dial tcp 127.0.0.1:42699: connect: connection refused
E0812 15:07:33.646670   10576 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:42699/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1213&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:42699: connect: connection refused
E0812 15:07:33.646680   10576 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:42699/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1213&timeout=10s&timeoutSeconds=522&watch=true: dial tcp 127.0.0.1:42699: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	77.142s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 260 lines ...
I0812 15:06:36.003954   11229 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0812 15:06:36.010112   11229 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=41081
I0812 15:06:36.016991   11229 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0812 15:06:36.129986   11229 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0812 15:06:36.130208   11229 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0812 15:06:36.383012   11229 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0812 15:06:38.450142   11229 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-9hgv5/test-cluster"
•E0812 15:06:38.954818   11229 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-qrfdw/test-cluster"
•E0812 15:06:39.560082   11229 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:42429/?timeout=50ms: dial tcp 127.0.0.1:42429: connect: connection refused"  "cluster"="cluster-cache-test-nnxmb/test-cluster"
•I0812 15:06:39.705210   11229 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":{}}}
I0812 15:06:40.205660   11229 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0812 15:06:40.205737   11229 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0812 15:06:40.205809   11229 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0812 15:06:40.742601   11229 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0812 15:06:40.742830   11229 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0812 15:06:40.809250   11229 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:37243/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:37243: connect: connection refused


Ran 5 of 5 Specs in 20.673 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (20.67s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	20.891s
?   	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
I0812 15:06:50.488223   11772 controller.go:130]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0812 15:06:50.489942   11772 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0812 15:06:50.491587   11772 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0812 15:06:50.491798   11772 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 94 lines ...
I0812 15:07:01.820238   11772 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-8r8fr" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-c72zl (m2-healthy-c72zl)","node-m3-healthy-t5wx6 (m3-healthy-t5wx6)"] "targetQuorum"=2 "targetTotalMembers"=2 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0812 15:07:01.829142   11772 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-8r8fr"
=== RUN   TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade)
I0812 15:07:02.091926   11772 remediation.go:195]  "msg"="etcd cluster before remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "currentMembers"=["node-m4-healthy-kzdb7","node-m1-unhealthy-md7rn","node-m2-healthy-74kpc","node-m3-healthy-86g6d"] "currentTotalMembers"=4
I0812 15:07:02.092025   11772 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-md7rn" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m4-healthy-kzdb7 (m4-healthy-kzdb7)","node-m2-healthy-74kpc (m2-healthy-74kpc)","node-m3-healthy-86g6d (m3-healthy-86g6d)"] "targetQuorum"=2 "targetTotalMembers"=3 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0812 15:07:02.097380   11772 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-md7rn"
--- FAIL: TestReconcileUnhealthyMachines (1.15s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_are_no_unhealthy_machines (0.00s)
    --- PASS: TestReconcileUnhealthyMachines/reconcileUnhealthyMachines_return_early_if_the_machine_to_be_remediated_is_marked_for_deletion (0.00s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_desired_replicas_<=_1 (0.04s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_number_of_machines_lower_than_desired (0.07s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_a_deleting_machine (0.08s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_at_least_one_additional_unhealthy_etcd_member_on_a_3_machine_CP (0.10s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_at_least_two_additional_unhealthy_etcd_member_on_a_5_machine_CP (0.13s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_2_CP_(during_1_CP_rolling_upgrade) (0.13s)
    --- FAIL: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_3_CP (0.24s)
        remediation_test.go:839: 
            Expected
                <string>: WaitingForRemediation
            to equal
                <string>: RemediationInProgress
    --- PASS: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade) (0.33s)
... skipping 81 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
I0812 15:07:05.333139   11772 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
I0812 15:07:05.333284   11772 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: 1660316795
Will run 1 of 1 specs

E0812 15:07:05.357668   11772 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-1lbekn\" not found" "kubeadmControlPlane"="kcp-foo-1lbekn" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.021 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0812 15:07:05.359324   11772 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-bmtcrr" "kubeadmControlPlane"="kcp-foo-bmtcrr" "namespace"="test" 
I0812 15:07:07.445791   11772 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-bmtcrr" "kubeadmControlPlane"="kcp-foo-bmtcrr" "namespace"="test" "needRollout"=["kcp-foo-bmtcrr-g4bl5"]
I0812 15:07:07.445966   11772 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-bmtcrr" "kubeadmControlPlane"="kcp-foo-bmtcrr" "namespace"="test" "failures"="[machine kcp-foo-bmtcrr-nxfph does not have APIServerPodHealthy condition, machine kcp-foo-bmtcrr-nxfph does not have ControllerManagerPodHealthy condition, machine kcp-foo-bmtcrr-nxfph does not have SchedulerPodHealthy condition, machine kcp-foo-bmtcrr-nxfph does not have EtcdPodHealthy condition, machine kcp-foo-bmtcrr-nxfph does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (2.09s)
FAIL
I0812 15:07:07.446848   11772 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	32.663s
I0812 15:06:48.850925   11720 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"
I0812 15:06:48.851121   11720 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0812 15:06:48.851158   11720 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"
I0812 15:06:48.851182   11720 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0812 15:06:48.851288   11720 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"
I0812 15:06:48.851316   11720 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1660316793
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: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1660316793
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0812 15:06:50.858951   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:06:59.182063   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:07:08.168259   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:07:19.298587   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:07:35.771867   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:07:48.780529   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:08:06.428000   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:08:27.351352   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:08:58.368205   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0812 15:09:43.525574   11720 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
E0812 15:09:43.534104   11720 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0812 15:09:43.534146   11720 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-961087884/tls.crt: no such file or directory"  
E0812 15:09:43.534164   11720 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0812 15:09:43.534181   11720 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-961087884/tls.crt: no such file or directory"  
I0812 15:09:43.534294   11720 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	190.507s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0812 15:06:59.877020   12024 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0812 15:06:59.877174   12024 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0812 15:06:59.977472   12024 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0812 15:07:00.080208   12024 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0812 15:07:00.080282   12024 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0812 15:07:00.202406   12024 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-bvb2c8"} 
E0812 15:07:00.231253   12024 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"
•I0812 15:07:01.295605   12024 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-7g36a4"} 
•E0812 15:07:01.337071   12024 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"
E0812 15:07:02.517172   12024 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"
E0812 15:07:03.542925   12024 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"
•E0812 15:07:04.754617   12024 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"
E0812 15:07:05.789646   12024 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"
••E0812 15:07:06.806251   12024 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0812 15:07:06.806303   12024 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-181114770/tls.crt: no such file or directory"  
E0812 15:07:06.806323   12024 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0812 15:07:06.806340   12024 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-181114770/tls.crt: no such file or directory"  
I0812 15:07:06.806544   12024 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0812 15:07:06.806604   12024 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0812 15:07:06.806645   12024 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0812 15:07:06.808381   12024 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 22.300 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (22.30s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	22.368s
?   	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.01s)
=== 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
E0812 15:06:50.362975   12258 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 96 lines ...
•I0812 15:07:04.857761   12258 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}}}
I0812 15:07:04.875216   12258 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0812 15:07:04.878048   12258 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 29 lines ...
•I0812 15:07:33.036878   15211 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

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

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