This job view page is being replaced by Spyglass soon. Check out the new job view.
PRCecileRobertMichon: 🐛 Use metadata.yaml in github repo to fetch latest release for older contracts
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2021-06-30 00:05
Elapsed4m25s
Revision213a2b802d4267006a470d6b70ab8c3b008b2a71
Refs 4867

No Test Failures!


Error lines from build-log.txt

... skipping 779 lines ...
I0630 00:07:14.820826    8528 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0630 00:07:15.292839    8528 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" 
•I0630 00:07:15.303277    8528 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 11.782 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.78s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	63.581s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 302 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0630 00:06:44.480033   10511 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":{}}}
I0630 00:06:44.480079   10511 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0630 00:06:44.480113   10511 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0630 00:06:44.480151   10511 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0630 00:06:44.480238   10511 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0630 00:06:44.480813   10511 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2021/06/30 00:06:44 http: TLS handshake error from 127.0.0.1:48858: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0630 00:06:44.677642   10511 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"
I0630 00:06:44.684801   10511 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0630 00:06:44.710732   10511 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
I0630 00:06:44.712148   10511 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"
E0630 00:06:44.712390   10511 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
I0630 00:06:44.712769   10511 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0630 00:06:44.996764   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0630 00:06:45.003376   10511 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0630 00:06:45.009885   10511 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-jjnr4" "namespace"="test-machine-watches-f9nn9" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0630 00:06:45.009977   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0630 00:06:45.119545   10511 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-jjnr4" "namespace"="test-machine-watches-f9nn9" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0630 00:06:45.119625   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0630 00:06:45.220115   10511 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-jjnr4" "namespace"="test-machine-watches-f9nn9" "noderef"="node-1"
E0630 00:06:45.248117   10511 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0630 00:06:45.248171   10511 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0630 00:06:45.301967   10511 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-jjnr4\" in namespace \"test-machine-watches-f9nn9\", requeuing: requeue in 1s"  
E0630 00:06:45.312207   10511 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-jjnr4\" in namespace \"test-machine-watches-f9nn9\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-jjnr4\" in namespace \"test-machine-watches-f9nn9\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-jjnr4" "namespace"="test-machine-watches-f9nn9"
--- PASS: TestWatches (0.64s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I0630 00:06:45.542385   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-kwkpg" "namespace"="test-machine-watches-f9nn9" "count"=1
I0630 00:06:45.542501   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-kwkpg" "namespace"="test-machine-watches-f9nn9" "descendants"="Worker machines: machine-created-jjnr4" "indirect descendants count"=0
I0630 00:06:45.556499   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-kwkpg" "namespace"="test-machine-watches-f9nn9" "count"=1
I0630 00:06:45.556566   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-kwkpg" "namespace"="test-machine-watches-f9nn9" "descendants"="Worker machines: machine-created-jjnr4" "indirect descendants count"=0
I0630 00:06:46.312914   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-kwkpg" "machine"="machine-created-jjnr4" "namespace"="test-machine-watches-f9nn9" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"33daf61c-ffb8-40cb-9560-09a935df8f79","apiVersion":"v1"}
E0630 00:06:46.356838   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-jjnr4\" not found" "controller"="machine" "name"="machine-created-jjnr4" "namespace"="test-machine-watches-f9nn9"
E0630 00:06:47.403682   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-j4m5w\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-pznzh\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-pznzh: secrets \"machine-reconcile-pznzh-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-j4m5w" "namespace"="default"
I0630 00:06:48.404265   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-pznzh" "machine"="machine-created-j4m5w" "namespace"="default" "cause"="noderef is nil" "node"=null
I0630 00:06:48.442035   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-pznzh" "machine"="machine-created-j4m5w" "namespace"="default" "cause"="noderef is nil" "node"=null
I0630 00:06:48.468667   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-pznzh" "machine"="machine-created-j4m5w" "namespace"="default" "cause"="noderef is nil" "node"=null
E0630 00:06:48.503470   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-j4m5w\" not found" "controller"="machine" "name"="machine-created-j4m5w" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.15s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.15s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
    --- PASS: TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one (0.00s)
    --- PASS: TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer (0.00s)
=== RUN   TestMachineOwnerReference
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0630 00:06:48.517219   10511 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0630 00:06:48.517400   10511 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
E0630 00:06:48.522470   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-pznzh\" not found" "controller"="cluster" "name"="machine-reconcile-pznzh" "namespace"="default"
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0630 00:06:48.524825   10511 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0630 00:06:48.524976   10511 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0630 00:06:48.532913   10511 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0630 00:06:48.533099   10511 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
... skipping 124 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
    --- 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
I0630 00:06:48.680104   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b8cg4" "namespace"="test-mhc-2rtm8" 
I0630 00:06:48.702787   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0630 00:06:48.703824   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-hcm4f\" not found"  "cluster"="test-mhc-2rtm8/test-cluster-hcm4f"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0630 00:06:48.735457   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-b8cg4\" not found" "controller"="machinehealthcheck" "name"="test-mhc-b8cg4" "namespace"="test-mhc-2rtm8"
=== 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
error cannot retrieve mhc in ctx: MachineHealthCheck.cluster.x-k8s.io "test-mhc-x5xlp" not foundI0630 00:06:49.735709   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-b8cg4" "namespace"="test-mhc-2rtm8" 
I0630 00:06:49.735816   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xgfsg" "namespace"="test-mhc-frxng" 
I0630 00:06:49.735854   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hjskl" "namespace"="test-mhc-tx9qn" 
I0630 00:06:49.735888   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x5xlp" "namespace"="test-mhc-wprh9" 
I0630 00:06:49.770924   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 00:06:49.820377   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x5xlp" "namespace"="test-mhc-wprh9" 
I0630 00:06:49.829836   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x5xlp" "namespace"="test-mhc-wprh9" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0630 00:06:49.834572   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x5xlp" "namespace"="test-mhc-wprh9" 
E0630 00:06:49.859091   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wprh9/test-cluster-4dzmv"
E0630 00:06:49.860354   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-4dzmv\" not found" "controller"="cluster" "name"="test-cluster-4dzmv" "namespace"="test-mhc-wprh9"
I0630 00:06:49.956347   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zrgbb" "namespace"="test-mhc-j72cn" 
I0630 00:06:49.975846   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 00:06:50.099893   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zrgbb" "namespace"="test-mhc-j72cn" 
I0630 00:06:50.105247   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zrgbb" "namespace"="test-mhc-j72cn" 
E0630 00:06:50.161053   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-j72cn/test-cluster-ms249"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0630 00:06:50.165649   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zrgbb" "namespace"="test-mhc-j72cn" 
I0630 00:06:50.289544   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
inframachine created: test-mhc-machine-infra-46ltb
I0630 00:06:50.303496   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-7zv9h
I0630 00:06:50.404092   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-7zv9h/"
node created: test-mhc-node-kkflt
E0630 00:06:50.458681   10511 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-kkflt"
E0630 00:06:50.458978   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kkflt, got []"  "node"="test-mhc-node-kkflt"
I0630 00:06:50.459212   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.459531   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-7zv9h/"
I0630 00:06:50.464683   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.465114   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-7zv9h/"
I0630 00:06:50.468273   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
inframachine created: test-mhc-machine-infra-qdz7g
machine created: test-mhc-machine-4847v
I0630 00:06:50.486984   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.492441   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.493492   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
... skipping 40 lines ...
I0630 00:06:50.581665   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.584551   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.588111   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.589624   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.592508   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.595757   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.596218   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
I0630 00:06:50.606449   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.606905   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
I0630 00:06:50.607839   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.608275   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
I0630 00:06:50.613851   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.614305   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
I0630 00:06:50.629865   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.630367   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
I0630 00:06:50.644973   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.645549   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
I0630 00:06:50.655444   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.656002   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
I0630 00:06:50.706320   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
node created: test-mhc-node-blx6l
E0630 00:06:50.706769   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-blx6l, got []"  "node"="test-mhc-node-blx6l"
I0630 00:06:50.706781   10511 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-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
E0630 00:06:50.706869   10511 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-blx6l"
I0630 00:06:50.723940   10511 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst" "noderef"="test-mhc-node-blx6l"
I0630 00:06:50.725432   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.770382   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
Cleaning up nodes, machines and infra machines.
I0630 00:06:50.782969   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.783469   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zhpst/test-mhc-6nl55/test-mhc-machine-7zv9h/"
I0630 00:06:50.815771   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
I0630 00:06:50.816316   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zhpst/test-mhc-6nl55/test-mhc-machine-7zv9h/"
I0630 00:06:50.816747   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zhpst/test-mhc-6nl55/test-mhc-machine-4847v/"
E0630 00:06:50.834234   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zhpst/test-cluster-f9khm"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-9xhhh
machine created: test-mhc-machine-qwb6b
E0630 00:06:50.887459   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-f9nn9/machine-reconcile-kwkpg"
E0630 00:06:50.954031   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
E0630 00:06:51.157990   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6nl55\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6nl55" "namespace"="test-mhc-zhpst"
E0630 00:06:51.967376   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
node created: test-mhc-node-lnnh4
inframachine created: test-mhc-machine-infra-mg4xl
machine created: test-mhc-machine-vztwk
I0630 00:06:52.158298   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.177066   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 00:06:52.305611   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6nl55" "namespace"="test-mhc-zhpst" 
... skipping 218 lines ...
I0630 00:06:52.957149   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.959130   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.961101   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.963119   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.965069   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.967036   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
E0630 00:06:52.968148   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:06:52.969036   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.971020   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.973002   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.974974   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.976905   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:52.979129   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
... skipping 418 lines ...
I0630 00:06:53.988230   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:53.991459   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:53.994172   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:53.995604   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:53.996649   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:53.997661   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
E0630 00:06:53.999717   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
I0630 00:06:53.999921   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:54.001364   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:54.002692   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:54.003817   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:54.004904   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:54.007011   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
... skipping 352 lines ...
I0630 00:06:55.006879   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:55.009051   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:55.011187   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:55.013708   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:55.014993   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:55.016135   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
E0630 00:06:55.017899   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:06:55.019859   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:55.020404   10511 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-rft6b/test-mhc-6t4j5/test-mhc-machine-vztwk/"
I0630 00:06:55.041065   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:55.041480   10511 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-rft6b/test-mhc-6t4j5/test-mhc-machine-vztwk/"
E0630 00:06:55.047371   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v69qs, got []"  "node"="test-mhc-node-v69qs"
node created: test-mhc-node-v69qs
I0630 00:06:55.058118   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
inframachine created: test-mhc-machine-infra-k2mct
I0630 00:06:55.082332   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
machine created: test-mhc-machine-74wwf
I0630 00:06:55.086500   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
... skipping 273 lines ...
I0630 00:06:56.017509   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.031340   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.036222   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.039395   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.042383   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.045680   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
E0630 00:06:56.048309   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
I0630 00:06:56.048681   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.049944   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.052280   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.055299   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.057671   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:56.060109   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
... skipping 314 lines ...
I0630 00:06:57.059795   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.061415   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.062790   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.064089   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.065897   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.071869   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
E0630 00:06:57.085003   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:06:57.085163   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.087112   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.088890   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.090718   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.092479   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:57.094209   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
... skipping 293 lines ...
I0630 00:06:58.088899   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.092636   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.095723   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.097152   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.100729   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.102063   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.102512   10511 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-rft6b/test-mhc-6t4j5/test-mhc-machine-74wwf/"
E0630 00:06:58.110215   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
E0630 00:06:58.111022   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-phjkj, got []"  "node"="test-mhc-node-phjkj"
node created: test-mhc-node-phjkj
I0630 00:06:58.114984   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.115434   10511 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-rft6b/test-mhc-6t4j5/test-mhc-machine-74wwf/"
Cleaning up nodes, machines and infra machines.
I0630 00:06:58.121429   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.123099   10511 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-rft6b/test-mhc-6t4j5/test-mhc-machine-74wwf/test-mhc-node-phjkj"
I0630 00:06:58.135537   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.136100   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rft6b/test-mhc-6t4j5/test-mhc-machine-74wwf/"
Cleaning up nodes, machines and infra machines.
I0630 00:06:58.146260   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:58.146790   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rft6b/test-mhc-6t4j5/test-mhc-machine-qwb6b/"
I0630 00:06:58.176295   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-c5f79" "namespace"="test-mhc-rft6b" "count"=2
I0630 00:06:58.176375   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c5f79" "namespace"="test-mhc-rft6b" "descendants"="Worker machines: test-mhc-machine-74wwf,test-mhc-machine-qwb6b,test-mhc-machine-vztwk" "indirect descendants count"=1
I0630 00:06:58.180289   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-c5f79" "namespace"="test-mhc-rft6b" "count"=2
I0630 00:06:58.180348   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c5f79" "namespace"="test-mhc-rft6b" "descendants"="Worker machines: test-mhc-machine-qwb6b,test-mhc-machine-vztwk,test-mhc-machine-74wwf" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0630 00:06:58.273113   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rft6b/test-mhc-6t4j5/test-mhc-machine-74wwf/"
E0630 00:06:58.276353   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6t4j5\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b"
inframachine created: test-mhc-machine-infra-4kkvz
machine created: test-mhc-machine-sqx4p
I0630 00:06:59.110751   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c5f79" "machine"="test-mhc-machine-vztwk" "namespace"="test-mhc-rft6b" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-v69qs"}
E0630 00:06:59.171142   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vztwk\" not found" "controller"="machine" "name"="test-mhc-machine-vztwk" "namespace"="test-mhc-rft6b"
I0630 00:06:59.276632   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6t4j5" "namespace"="test-mhc-rft6b" 
I0630 00:06:59.276743   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:06:59.292806   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 00:06:59.409395   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:06:59.414337   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:06:59.415068   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:06:59.455846   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:06:59.536880   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:06:59.697971   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:00.021485   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:00.177306   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:00.663409   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:01.177847   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c5f79" "machine"="test-mhc-machine-74wwf" "namespace"="test-mhc-rft6b" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-phjkj"}
E0630 00:07:01.219733   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-74wwf\" not found" "controller"="machine" "name"="test-mhc-machine-74wwf" "namespace"="test-mhc-rft6b"
I0630 00:07:01.944482   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:02.220130   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
I0630 00:07:03.180346   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-c5f79" "namespace"="test-mhc-rft6b" "count"=1
I0630 00:07:03.180462   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c5f79" "namespace"="test-mhc-rft6b" "descendants"="Worker machines: test-mhc-machine-qwb6b" "indirect descendants count"=0
I0630 00:07:03.220684   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c5f79" "machine"="test-mhc-machine-qwb6b" "namespace"="test-mhc-rft6b" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-lnnh4"}
E0630 00:07:03.273154   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qwb6b\" not found" "controller"="machine" "name"="test-mhc-machine-qwb6b" "namespace"="test-mhc-rft6b"
I0630 00:07:04.281700   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:04.287579   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:04.287826   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:04.312556   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:04.335576   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w6vmz, got []"  "node"="test-mhc-node-w6vmz"
E0630 00:07:04.335865   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w6vmz, got []"  "node"="test-mhc-node-w6vmz"
node created: test-mhc-node-w6vmz
I0630 00:07:04.342804   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
inframachine created: test-mhc-machine-infra-fgsb9
machine created: test-mhc-machine-8wsf6
I0630 00:07:04.361478   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:04.374315   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:04.379456   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:04.400747   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:04.442029   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:04.523317   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:04.689226   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:05.010593   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:05.287973   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
I0630 00:07:05.651992   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.302826   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.304823   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.315969   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.331817   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.338625   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.347699   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:06.352358   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:06.352647   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.371369   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
node created: test-mhc-node-4pzx2
E0630 00:07:06.375299   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4pzx2, got []"  "node"="test-mhc-node-4pzx2"
E0630 00:07:06.375470   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4pzx2, got []"  "node"="test-mhc-node-4pzx2"
I0630 00:07:06.381841   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
inframachine created: test-mhc-machine-infra-2rc2j
I0630 00:07:06.394286   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
machine created: test-mhc-machine-dwd42
I0630 00:07:06.396050   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.406188   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.411558   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:06.933658   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:07.352797   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
E0630 00:07:08.193312   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rft6b/test-cluster-c5f79"
I0630 00:07:08.363315   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:08.373764   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:08.389295   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:08.408743   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:08.420844   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:08.425087   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:08.430328   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:08.430859   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:08.449345   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
E0630 00:07:08.506321   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-72gsz, got []"  "node"="test-mhc-node-72gsz"
node created: test-mhc-node-72gsz
I0630 00:07:08.520544   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
Cleaning up nodes, machines and infra machines.
I0630 00:07:08.534954   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
Cleaning up nodes, machines and infra machines.
I0630 00:07:08.583911   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-sdjns" "namespace"="test-mhc-2trdp" "count"=2
... skipping 4 lines ...
inframachine created: test-mhc-machine-infra-8zk5w
machine created: test-mhc-machine-xpd6n
I0630 00:07:08.677078   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:08.705287   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 00:07:08.722585   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w89b6" "namespace"="test-mhc-2trdp" 
I0630 00:07:08.722651   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
E0630 00:07:09.430756   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
I0630 00:07:10.431277   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-sdjns" "machine"="test-mhc-machine-sqx4p" "namespace"="test-mhc-2trdp" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-w6vmz"}
E0630 00:07:10.473664   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-sqx4p\" not found" "controller"="machine" "name"="test-mhc-machine-sqx4p" "namespace"="test-mhc-2trdp"
I0630 00:07:11.474194   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-sdjns" "machine"="test-mhc-machine-8wsf6" "namespace"="test-mhc-2trdp" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4pzx2"}
E0630 00:07:11.521421   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8wsf6\" not found" "controller"="machine" "name"="test-mhc-machine-8wsf6" "namespace"="test-mhc-2trdp"
I0630 00:07:12.521943   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-sdjns" "machine"="test-mhc-machine-dwd42" "namespace"="test-mhc-2trdp" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-72gsz"}
E0630 00:07:12.563664   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dwd42\" not found" "controller"="machine" "name"="test-mhc-machine-dwd42" "namespace"="test-mhc-2trdp"
I0630 00:07:13.572384   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
E0630 00:07:13.582970   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:13.582994   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
E0630 00:07:13.599017   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-2trdp/test-cluster-sdjns"
node created: test-mhc-node-gg2jx
E0630 00:07:13.678056   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gg2jx, got []"  "node"="test-mhc-node-gg2jx"
I0630 00:07:13.685579   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
inframachine created: test-mhc-machine-infra-f9mfk
machine created: test-mhc-machine-z992b
I0630 00:07:13.703203   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:13.712526   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
E0630 00:07:14.583337   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
I0630 00:07:15.596154   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:15.604533   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:15.619534   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:15.628240   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:15.639189   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
E0630 00:07:15.641873   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:15.642661   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
node created: test-mhc-node-gfw4h
E0630 00:07:15.715659   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gfw4h, got []"  "node"="test-mhc-node-gfw4h"
I0630 00:07:15.727330   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
inframachine created: test-mhc-machine-infra-wqs4s
machine created: test-mhc-machine-5hdpt
I0630 00:07:15.747300   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:15.754063   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:15.759871   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.657131   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.671833   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.682523   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.699651   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.704929   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.715723   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.719843   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
E0630 00:07:16.720285   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
Cleaning up nodes, machines and infra machines.
I0630 00:07:16.755752   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
Cleaning up nodes, machines and infra machines.
I0630 00:07:16.764858   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.765400   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xhldn/test-mhc-fkdjg/test-mhc-machine-xpd6n/"
I0630 00:07:16.805348   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:16.805948   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xhldn/test-mhc-fkdjg/test-mhc-machine-xpd6n/"
I0630 00:07:16.806410   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xhldn/test-mhc-fkdjg/test-mhc-machine-z992b/"
I0630 00:07:16.821033   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-484vl" "namespace"="test-mhc-xhldn" "count"=2
I0630 00:07:16.821122   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-484vl" "namespace"="test-mhc-xhldn" "descendants"="Worker machines: test-mhc-machine-xpd6n,test-mhc-machine-z992b,test-mhc-machine-5hdpt" "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
I0630 00:07:16.832071   10511 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-484vl" "namespace"="test-mhc-xhldn" "count"=2
I0630 00:07:16.832132   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-484vl" "namespace"="test-mhc-xhldn" "descendants"="Worker machines: test-mhc-machine-xpd6n,test-mhc-machine-z992b,test-mhc-machine-5hdpt" "indirect descendants count"=1
E0630 00:07:16.835814   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-fkdjg\" not found" "controller"="machinehealthcheck" "name"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn"
inframachine created: test-mhc-machine-infra-mgncj
machine created: test-mhc-machine-7sx9f
I0630 00:07:17.720817   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-484vl" "machine"="test-mhc-machine-xpd6n" "namespace"="test-mhc-xhldn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gg2jx"}
E0630 00:07:17.783682   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xpd6n\" not found" "controller"="machine" "name"="test-mhc-machine-xpd6n" "namespace"="test-mhc-xhldn"
I0630 00:07:17.838067   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fkdjg" "namespace"="test-mhc-xhldn" 
I0630 00:07:17.838178   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:17.859020   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 00:07:17.880334   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:17.881382   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:17.883209   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
... skipping 461 lines ...
I0630 00:07:18.821225   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.822980   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.824667   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.826383   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.828033   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.829705   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
E0630 00:07:18.830416   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-z992b\" not found" "controller"="machine" "name"="test-mhc-machine-z992b" "namespace"="test-mhc-xhldn"
I0630 00:07:18.831400   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.833041   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.834710   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.836584   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.838293   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:18.840048   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
... skipping 504 lines ...
I0630 00:07:19.891511   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.893767   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.895584   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.897765   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.899927   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.901915   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
E0630 00:07:19.904094   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5hdpt\" not found" "controller"="machine" "name"="test-mhc-machine-5hdpt" "namespace"="test-mhc-xhldn"
I0630 00:07:19.904171   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.906997   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.908714   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.910316   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.912429   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:19.914101   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
... skipping 437 lines ...
I0630 00:07:20.911829   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:20.913484   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:20.914035   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:20.915684   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:20.917434   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:20.918048   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:20.918290   10511 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-8g49x/test-mhc-jxc7m/test-mhc-machine-7sx9f/"
E0630 00:07:20.918588   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:20.949345   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:20.949738   10511 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-8g49x/test-mhc-jxc7m/test-mhc-machine-7sx9f/"
E0630 00:07:20.988931   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zj2jt, got []"  "node"="test-mhc-node-zj2jt"
node created: test-mhc-node-zj2jt
E0630 00:07:20.989169   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zj2jt, got []"  "node"="test-mhc-node-zj2jt"
I0630 00:07:21.001080   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:21.018879   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:21.025711   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:21.026084   10511 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-8g49x/test-mhc-jxc7m/test-mhc-machine-7sx9f/test-mhc-node-zj2jt"
I0630 00:07:21.047309   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:21.047708   10511 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-8g49x/test-mhc-jxc7m/test-mhc-machine-7sx9f/test-mhc-node-zj2jt"
Cleaning up nodes, machines and infra machines.
I0630 00:07:21.066934   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:21.067494   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8g49x/test-mhc-jxc7m/test-mhc-machine-7sx9f/"
I0630 00:07:21.083517   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:21.084371   10511 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8g49x/test-mhc-jxc7m/test-mhc-machine-7sx9f/"
I0630 00:07:21.092265   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-llksp" "namespace"="test-mhc-8g49x" "descendants"="Worker machines: test-mhc-machine-7sx9f" "indirect descendants count"=1
I0630 00:07:21.099189   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-llksp" "namespace"="test-mhc-8g49x" "descendants"="Worker machines: test-mhc-machine-7sx9f" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0630 00:07:21.104004   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jxc7m" "namespace"="test-mhc-8g49x" 
I0630 00:07:21.204499   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" "creating"=1 "need"=1
I0630 00:07:21.204551   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:21.218278   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-2r6tz-s2x4b\"" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:21.292200   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:21.310496   10511 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 00:07:21.430783   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:21.431660   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
E0630 00:07:21.846553   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xhldn/test-cluster-484vl"
E0630 00:07:21.922627   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
I0630 00:07:22.430978   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:22.923202   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-llksp" "machine"="test-mhc-machine-7sx9f" "namespace"="test-mhc-8g49x" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zj2jt"}
E0630 00:07:22.964050   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7sx9f\" not found" "controller"="machine" "name"="test-mhc-machine-7sx9f" "namespace"="test-mhc-8g49x"
I0630 00:07:23.432054   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.972694   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.972752   10511 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.976713   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.976770   10511 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.987619   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2r6tz-s2x4b" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.987671   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2r6tz-s2x4b" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.993758   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:23.994598   10511 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.005432   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.005792   10511 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-m9bb4/test-mhc-746kq/mhc-ms-2r6tz-s2x4b/"
I0630 00:07:24.007158   10511 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.012639   10511 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.014153   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2r6tz-s2x4b" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.014197   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2r6tz-s2x4b" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.021610   10511 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2r6tz" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.022869   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
... skipping 26 lines ...
I0630 00:07:24.309740   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.310997   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.312290   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.313983   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.316969   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.317281   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-h6jnm" "machine"="mhc-ms-2r6tz-s2x4b" "namespace"="test-mhc-m9bb4" "cause"="cluster is being deleted" "node"=null
E0630 00:07:24.360420   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jtdfx, got []"  "node"="test-mhc-node-jtdfx"
node created: test-mhc-node-jtdfx
E0630 00:07:24.360585   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jtdfx, got []"  "node"="test-mhc-node-jtdfx"
E0630 00:07:24.360781   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jtdfx, got []"  "node"="test-mhc-node-jtdfx"
E0630 00:07:24.370251   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-2r6tz-s2x4b\" not found" "controller"="machine" "name"="mhc-ms-2r6tz-s2x4b" "namespace"="test-mhc-m9bb4"
I0630 00:07:24.383472   10511 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-8zt8r" "target"="test-mhc-6zrtn/test-mhc-nrjd6/test-mhc-machine-8zt8r/"
I0630 00:07:24.396327   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.427147   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.429735   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.434204   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-746kq" "namespace"="test-mhc-m9bb4" 
I0630 00:07:24.435498   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.439743   10511 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-8zt8r" "target"="test-mhc-6zrtn/test-mhc-nrjd6/test-mhc-machine-8zt8r/test-mhc-node-jtdfx"
I0630 00:07:24.463725   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
Cleaning up nodes, machines and infra machines.
I0630 00:07:24.472644   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.475796   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.479776   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrjd6" "namespace"="test-mhc-6zrtn" 
I0630 00:07:24.485963   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rmnx7" "namespace"="test-mhc-6zrtn" "descendants"="Worker machines: test-mhc-machine-8zt8r" "indirect descendants count"=1
... skipping 371 lines ...
I0630 00:07:25.401120   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.403015   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.404680   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.406470   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.408353   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.410072   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
E0630 00:07:25.410208   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8zt8r\" not found" "controller"="machine" "name"="test-mhc-machine-8zt8r" "namespace"="test-mhc-6zrtn"
I0630 00:07:25.411834   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.413618   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.415317   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.417106   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.418834   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:25.420523   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
... skipping 327 lines ...
I0630 00:07:26.113625   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.115327   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.117016   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.118701   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.120442   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.122154   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
E0630 00:07:26.123335   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8g49x/test-cluster-llksp"
I0630 00:07:26.123863   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.125550   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.127262   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.129018   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.130782   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.132520   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
... skipping 144 lines ...
I0630 00:07:26.425043   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.427328   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.428119   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.429368   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.430866   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.432422   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
E0630 00:07:26.432764   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
I0630 00:07:26.436081   10511 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-bltc9" "target"="test-mhc-tmftd/test-mhc-dd7rw/test-mhc-machine-bltc9/"
I0630 00:07:26.452859   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
E0630 00:07:26.467781   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-687wg, got []"  "node"="test-mhc-node-687wg"
node created: test-mhc-node-687wg
E0630 00:07:26.468610   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-687wg, got []"  "node"="test-mhc-node-687wg"
E0630 00:07:26.468805   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-687wg, got []"  "node"="test-mhc-node-687wg"
I0630 00:07:26.476634   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.499226   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.505813   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.512328   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.514432   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.517378   10511 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-bltc9" "target"="test-mhc-tmftd/test-mhc-dd7rw/test-mhc-machine-bltc9/test-mhc-node-687wg"
I0630 00:07:26.534474   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.538016   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.540687   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.559783   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.561777   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
Cleaning up nodes, machines and infra machines.
I0630 00:07:26.602039   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.605244   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.611276   10511 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-bltc9" "target"="test-mhc-tmftd/test-mhc-dd7rw/test-mhc-machine-bltc9/"
I0630 00:07:26.625695   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-498qh" "namespace"="test-mhc-tmftd" "descendants"="Worker machines: test-mhc-machine-bltc9" "indirect descendants count"=1
I0630 00:07:26.636014   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
I0630 00:07:26.636813   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-498qh" "namespace"="test-mhc-tmftd" "descendants"="Worker machines: test-mhc-machine-bltc9" "indirect descendants count"=1
I0630 00:07:26.642127   10511 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dd7rw" "namespace"="test-mhc-tmftd" 
--- PASS: TestMachineHealthCheck_Reconcile (37.98s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.07s)
... skipping 14 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.40s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.15s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0630 00:07:26.645613   10511 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
E0630 00:07:26.647394   10511 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
E0630 00:07:26.649251   10511 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0630 00:07:26.649512   10511 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
E0630 00:07:26.652582   10511 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
I0630 00:07:26.656320   10511 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0630 00:07:26.656973   10511 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0630 00:07:26.658854   10511 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0630 00:07:26.669679   10511 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
E0630 00:07:26.671921   10511 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 82 lines ...
I0630 00:07:26.701028   10511 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"
•I0630 00:07:26.703249   10511 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"
I0630 00:07:26.704194   10511 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"
I0630 00:07:26.705062   10511 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0630 00:07:26.705105   10511 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0630 00:07:26.705822   10511 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0630 00:07:26.707699   10511 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" 
•I0630 00:07:26.823893   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-ggb8r" "namespace"="ms-test" "creating"=2 "need"=2
I0630 00:07:26.823960   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-ggb8r" "namespace"="ms-test" 
I0630 00:07:26.841186   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-ggb8r-p86kc\"" "machineset"="ms-ggb8r" "namespace"="ms-test" 
I0630 00:07:26.841247   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-ggb8r" "namespace"="ms-test" 
I0630 00:07:26.857706   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-ggb8r-qgmn4\"" "machineset"="ms-ggb8r" "namespace"="ms-test" 
I0630 00:07:26.983816   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-ggb8r" "namespace"="ms-test" "creating"=1 "need"=2
I0630 00:07:26.983861   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-ggb8r" "namespace"="ms-test" 
I0630 00:07:27.002872   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-ggb8r-j2bj4\"" "machineset"="ms-ggb8r" "namespace"="ms-test" 
E0630 00:07:27.054303   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.054359   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.054395   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.201738   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.201813   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.201997   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.202037   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.202203   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.202241   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-qgmn4-2bgs5, got []"  "node"="ms-ggb8r-qgmn4-2bgs5"
E0630 00:07:27.248931   10511 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-ggb8r-qgmn4-2bgs5 for machine ms-test/ms-ggb8r-qgmn4: the cache is not started, can not read objects" "machineset"="ms-ggb8r" "namespace"="ms-test" 
E0630 00:07:27.265756   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.266212   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.267004   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.270935   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.272119   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.271442   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.272177   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.271683   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
E0630 00:07:27.272230   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-ggb8r-j2bj4-kd92c, got []"  "node"="ms-ggb8r-j2bj4-kd92c"
I0630 00:07:27.421221   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-ggb8r-qgmn4,ms-ggb8r-j2bj4" "indirect descendants count"=2
I0630 00:07:27.425228   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-ggb8r-j2bj4,ms-ggb8r-qgmn4" "indirect descendants count"=2
•I0630 00:07:27.433122   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-498qh" "machine"="test-mhc-machine-bltc9" "namespace"="test-mhc-tmftd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-687wg"}
E0630 00:07:27.506429   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-bltc9\" not found" "controller"="machine" "name"="test-mhc-machine-bltc9" "namespace"="test-mhc-tmftd"
I0630 00:07:27.523544   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0630 00:07:27.523592   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" 
I0630 00:07:27.536893   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-6gllg-6657c7fddb-vzskm\"" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" 
I0630 00:07:27.536940   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" 
I0630 00:07:27.553474   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-6gllg-6657c7fddb-fm8mm\"" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" 
I0630 00:07:27.664149   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
... skipping 4 lines ...
I0630 00:07:27.721046   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0630 00:07:27.721095   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" 
I0630 00:07:27.736639   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gllg-6657c7fddb-sbpkw\"" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" 
I0630 00:07:27.824931   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0630 00:07:27.824973   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" 
I0630 00:07:27.838825   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gllg-cdfc6fd6c-xdkkw\"" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" 
E0630 00:07:27.915379   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.915379   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.915505   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.918931   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.918987   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.918931   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.919094   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.918930   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.919128   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-xdkkw-j6m57, got []"  "node"="md-6gllg-cdfc6fd6c-xdkkw-j6m57"
E0630 00:07:27.955479   10511 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-6gllg-cdfc6fd6c-xdkkw-j6m57 for machine md-test/md-6gllg-cdfc6fd6c-xdkkw: the cache is not started, can not read objects" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" 
I0630 00:07:27.991666   10511 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0630 00:07:27.991728   10511 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0630 00:07:27.997409   10511 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "machine"="md-6gllg-6657c7fddb-8d27g"
I0630 00:07:28.107558   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0630 00:07:28.107598   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" 
I0630 00:07:28.118517   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gllg-cdfc6fd6c-jznq7\"" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" 
E0630 00:07:28.159842   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.159850   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.160084   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.168576   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.169003   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.169042   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.169103   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.168874   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
E0630 00:07:28.169132   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-jznq7-8958w, got []"  "node"="md-6gllg-cdfc6fd6c-jznq7-8958w"
I0630 00:07:28.207455   10511 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0630 00:07:28.207501   10511 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0630 00:07:28.212894   10511 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "machine"="md-6gllg-6657c7fddb-sbpkw"
I0630 00:07:28.236704   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0630 00:07:28.236761   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" 
I0630 00:07:28.249359   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gllg-cdfc6fd6c-cl7tk\"" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" 
E0630 00:07:28.310092   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.310092   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.310247   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.314706   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.314759   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.314765   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.314804   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.314854   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
E0630 00:07:28.314907   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-cdfc6fd6c-cl7tk-qczgf, got []"  "node"="md-6gllg-cdfc6fd6c-cl7tk-qczgf"
I0630 00:07:28.377583   10511 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0630 00:07:28.377635   10511 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0630 00:07:28.382352   10511 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" "machine"="md-6gllg-6657c7fddb-qb7pz"
E0630 00:07:28.406010   10511 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-6gllg-6657c7fddb\" not found" "machineset"="md-6gllg-6657c7fddb" "namespace"="md-test" 
E0630 00:07:28.406087   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-6gllg-6657c7fddb\" not found" "controller"="machineset" "name"="md-6gllg-6657c7fddb" "namespace"="md-test"
E0630 00:07:28.531853   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
E0630 00:07:29.064105   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-m9bb4/test-cluster-h6jnm"
I0630 00:07:29.410267   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0630 00:07:29.410308   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" 
I0630 00:07:29.418841   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gllg-74d45c49c5-ddf77\"" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" 
E0630 00:07:29.543024   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6zrtn/test-cluster-rmnx7"
E0630 00:07:29.547138   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-ddf77-fmpxw, got []"  "node"="md-6gllg-74d45c49c5-ddf77-fmpxw"
E0630 00:07:29.550684   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-ddf77-fmpxw, got []"  "node"="md-6gllg-74d45c49c5-ddf77-fmpxw"
E0630 00:07:29.550735   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-ddf77-fmpxw, got []"  "node"="md-6gllg-74d45c49c5-ddf77-fmpxw"
I0630 00:07:29.605973   10511 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0630 00:07:29.606012   10511 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0630 00:07:29.619389   10511 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "machine"="md-6gllg-cdfc6fd6c-jznq7"
I0630 00:07:29.732933   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0630 00:07:29.732973   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" 
I0630 00:07:29.742577   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gllg-74d45c49c5-xrhrh\"" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" 
I0630 00:07:29.746929   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:29.746955   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:29.760652   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
I0630 00:07:29.760689   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
E0630 00:07:29.796575   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-cdfc6fd6c-xdkkw\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-cdfc6fd6c-xdkkw" "namespace"="md-test"
E0630 00:07:29.800487   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-xrhrh-29s7l, got []"  "node"="md-6gllg-74d45c49c5-xrhrh-29s7l"
E0630 00:07:29.803097   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-xrhrh-29s7l, got []"  "node"="md-6gllg-74d45c49c5-xrhrh-29s7l"
E0630 00:07:29.803157   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-xrhrh-29s7l, got []"  "node"="md-6gllg-74d45c49c5-xrhrh-29s7l"
I0630 00:07:29.880641   10511 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0630 00:07:29.880694   10511 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0630 00:07:29.883664   10511 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "machine"="md-6gllg-cdfc6fd6c-cl7tk"
I0630 00:07:29.993529   10511 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0630 00:07:29.993597   10511 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" 
I0630 00:07:30.003996   10511 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gllg-74d45c49c5-j6crw\"" "machineset"="md-6gllg-74d45c49c5" "namespace"="md-test" 
E0630 00:07:30.068571   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-j6crw-2j8w4, got []"  "node"="md-6gllg-74d45c49c5-j6crw-2j8w4"
E0630 00:07:30.172181   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-j6crw-2j8w4, got []"  "node"="md-6gllg-74d45c49c5-j6crw-2j8w4"
E0630 00:07:30.172222   10511 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6gllg-74d45c49c5-j6crw-2j8w4, got []"  "node"="md-6gllg-74d45c49c5-j6crw-2j8w4"
I0630 00:07:30.201299   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-6gllg-cdfc6fd6c,md-6gllg-74d45c49c5;Worker machines: md-6gllg-74d45c49c5-xrhrh,md-6gllg-74d45c49c5-j6crw,md-6gllg-6657c7fddb-vzskm,md-6gllg-6657c7fddb-fm8mm,md-6gllg-74d45c49c5-ddf77,md-6gllg-cdfc6fd6c-jznq7,md-6gllg-cdfc6fd6c-cl7tk,md-6gllg-cdfc6fd6c-xdkkw" "indirect descendants count"=10
I0630 00:07:30.206023   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-6gllg-74d45c49c5,md-6gllg-cdfc6fd6c;Worker machines: md-6gllg-74d45c49c5-j6crw,md-6gllg-6657c7fddb-vzskm,md-6gllg-6657c7fddb-fm8mm,md-6gllg-74d45c49c5-ddf77,md-6gllg-cdfc6fd6c-jznq7,md-6gllg-cdfc6fd6c-cl7tk,md-6gllg-cdfc6fd6c-xdkkw,md-6gllg-74d45c49c5-xrhrh" "indirect descendants count"=10
•E0630 00:07:30.208505   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-6gllg\" not found" "controller"="machinedeployment" "name"="md-6gllg" "namespace"="md-test"
I0630 00:07:30.211545   10511 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0630 00:07:30.211595   10511 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0630 00:07:30.215530   10511 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gllg-cdfc6fd6c" "namespace"="md-test" "machine"="md-6gllg-cdfc6fd6c-xdkkw"
•E0630 00:07:30.330004   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-j5bdh\" not found" "controller"="cluster" "name"="test1-j5bdh" "namespace"="default"
I0630 00:07:30.797102   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-6gllg-cdfc6fd6c-jznq7" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-6gllg-cdfc6fd6c-jznq7-8958w"}
I0630 00:07:30.821191   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-6gllg-cdfc6fd6c-cl7tk" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-6gllg-cdfc6fd6c-cl7tk-qczgf"}
E0630 00:07:30.900348   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-ddf77\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-ddf77" "namespace"="md-test"
•I0630 00:07:31.448429   10511 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-v76n8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0630 00:07:31.565564   10511 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-v76n8" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0630 00:07:31.569390   10511 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-v76n8" "namespace"="default"
I0630 00:07:31.920110   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:31.920144   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:31.923616   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
I0630 00:07:31.923709   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
I0630 00:07:31.924203   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-6gllg-cdfc6fd6c-xdkkw" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-6gllg-cdfc6fd6c-xdkkw-j6m57"}
I0630 00:07:31.957109   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-6gllg-cdfc6fd6c-jznq7" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-6gllg-cdfc6fd6c-jznq7-8958w"}
E0630 00:07:31.980780   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-6gllg-cdfc6fd6c-jznq7\" not found" "controller"="machine" "name"="md-6gllg-cdfc6fd6c-jznq7" "namespace"="md-test"
E0630 00:07:32.581898   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
•I0630 00:07:32.981227   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-6gllg-cdfc6fd6c-cl7tk" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-6gllg-cdfc6fd6c-cl7tk-qczgf"}
E0630 00:07:33.005356   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-6gllg-cdfc6fd6c-cl7tk\" not found" "controller"="machine" "name"="md-6gllg-cdfc6fd6c-cl7tk" "namespace"="md-test"
E0630 00:07:33.592111   10511 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tmftd/test-cluster-498qh"
I0630 00:07:33.592532   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-ggb8r-qgmn4,ms-ggb8r-j2bj4" "indirect descendants count"=2
E0630 00:07:33.604601   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-7bm5z\" not found" "controller"="cluster" "name"="test3-7bm5z" "namespace"="default"
E0630 00:07:34.019347   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-ddf77\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-ddf77" "namespace"="md-test"
E0630 00:07:34.605282   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
E0630 00:07:35.042625   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-xrhrh\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-xrhrh" "namespace"="md-test"
E0630 00:07:35.614928   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
•I0630 00:07:36.043181   10511 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-6gllg-cdfc6fd6c-xdkkw" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-6gllg-cdfc6fd6c-xdkkw-j6m57"}
E0630 00:07:36.072977   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-6gllg-cdfc6fd6c-xdkkw\" not found" "controller"="machine" "name"="md-6gllg-cdfc6fd6c-xdkkw" "namespace"="md-test"
I0630 00:07:36.615546   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-6gllg-74d45c49c5,md-6gllg-cdfc6fd6c;Worker machines: md-6gllg-6657c7fddb-vzskm,md-6gllg-6657c7fddb-fm8mm,md-6gllg-74d45c49c5-ddf77,md-6gllg-74d45c49c5-xrhrh,md-6gllg-74d45c49c5-j6crw" "indirect descendants count"=7
E0630 00:07:36.619847   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
I0630 00:07:37.100037   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:37.100090   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:37.103635   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
I0630 00:07:37.103670   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
E0630 00:07:37.107183   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-ddf77\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-ddf77" "namespace"="md-test"
E0630 00:07:37.620741   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
E0630 00:07:38.113044   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-xrhrh\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-xrhrh" "namespace"="md-test"
E0630 00:07:38.629296   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
•E0630 00:07:39.113438   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-7zv9h\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-7zv9h" "namespace"="test-mhc-zhpst"
E0630 00:07:39.630036   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
E0630 00:07:40.121930   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-ddf77\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-ddf77" "namespace"="md-test"
I0630 00:07:40.630613   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-ggb8r-j2bj4,ms-ggb8r-qgmn4" "indirect descendants count"=2
E0630 00:07:40.631076   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
I0630 00:07:41.126418   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:41.126478   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:41.130441   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
I0630 00:07:41.130520   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
E0630 00:07:41.135259   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-xrhrh\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-xrhrh" "namespace"="md-test"
E0630 00:07:41.640607   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
E0630 00:07:42.135769   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-f9khm\" for machine \"test-mhc-machine-4847v\" in namespace \"test-mhc-zhpst\": Cluster.cluster.x-k8s.io \"test-cluster-f9khm\" not found" "controller"="machine" "name"="test-mhc-machine-4847v" "namespace"="test-mhc-zhpst"
E0630 00:07:42.641301   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
E0630 00:07:43.140905   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-ddf77\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-ddf77" "namespace"="md-test"
I0630 00:07:43.641904   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-6gllg-74d45c49c5,md-6gllg-cdfc6fd6c;Worker machines: md-6gllg-74d45c49c5-xrhrh,md-6gllg-74d45c49c5-j6crw,md-6gllg-6657c7fddb-vzskm,md-6gllg-6657c7fddb-fm8mm,md-6gllg-74d45c49c5-ddf77" "indirect descendants count"=7
E0630 00:07:43.642754   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
E0630 00:07:44.146085   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-xrhrh\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-xrhrh" "namespace"="md-test"
E0630 00:07:44.643495   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
I0630 00:07:45.167033   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:45.167095   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:45.170531   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
I0630 00:07:45.170561   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
E0630 00:07:45.174050   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-ddf77\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-ddf77" "namespace"="md-test"
E0630 00:07:45.644346   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
E0630 00:07:46.179263   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-xrhrh\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-xrhrh" "namespace"="md-test"
E0630 00:07:46.645072   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
I0630 00:07:47.193295   10511 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-6nw29" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0630 00:07:47.202244   10511 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-6nw29" "namespace"="default" 
E0630 00:07:47.215352   10511 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-6nw29" "namespace"="default"
I0630 00:07:47.645639   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-ggb8r-j2bj4,ms-ggb8r-qgmn4" "indirect descendants count"=2
E0630 00:07:47.646105   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
E0630 00:07:48.220467   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-ddf77\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-ddf77" "namespace"="md-test"
E0630 00:07:48.646832   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-v76n8: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-v76n8" "namespace"="default"
I0630 00:07:49.227735   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:49.227778   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-vzskm" "namespace"="md-test" 
I0630 00:07:49.231342   10511 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
I0630 00:07:49.231377   10511 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-6gllg-6657c7fddb-fm8mm" "namespace"="md-test" 
E0630 00:07:49.235662   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-6gllg-74d45c49c5-xrhrh\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-6gllg-74d45c49c5-xrhrh" "namespace"="md-test"
E0630 00:07:49.647528   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"
I0630 00:07:50.249334   10511 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-6nw29" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0630 00:07:50.249649   10511 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-6nw29" "namespace"="default" "noderef"="id-node-1"
E0630 00:07:50.262158   10511 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-6nw29" "namespace"="default"
I0630 00:07:50.648231   10511 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-6gllg-74d45c49c5,md-6gllg-cdfc6fd6c;Worker machines: md-6gllg-6657c7fddb-vzskm,md-6gllg-6657c7fddb-fm8mm,md-6gllg-74d45c49c5-ddf77,md-6gllg-74d45c49c5-xrhrh,md-6gllg-74d45c49c5-j6crw" "indirect descendants count"=7
E0630 00:07:50.652113   10511 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-77qdq: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-77qdq" "namespace"="default"

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


Ran 16 of 16 Specs in 24.084 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (24.08s)
PASS
Tearing down test suite
E0630 00:07:50.758484   10511 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0630 00:07:50.758543   10511 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
E0630 00:07:50.758546   10511 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-797739837/tls.crt: no such file or directory"  
I0630 00:07:50.758562   10511 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0630 00:07:50.758616   10511 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0630 00:07:50.758657   10511 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0630 00:07:50.758682   10511 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0630 00:07:50.758711   10511 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0630 00:07:50.758572   10511 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0630 00:07:50.758899   10511 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
E0630 00:07:50.758919   10511 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-797739837/tls.crt: no such file or directory"  
E0630 00:07:50.787146   10511 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:41097/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1272&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:41097: connect: connection refused
E0630 00:07:50.787381   10511 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:41097/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1272&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:41097: connect: connection refused
E0630 00:07:50.787517   10511 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:41097/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1272&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:41097: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	79.876s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0630 00:06:45.559727   10831 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0630 00:06:45.575534   10831 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":{}}}
I0630 00:06:45.777180   10831 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0630 00:06:45.777246   10831 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0630 00:06:45.777329   10831 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0630 00:06:46.302629   10831 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0630 00:06:48.339443   10831 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-6f5nq/test-cluster"
•E0630 00:06:48.791157   10831 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-shj5z/test-cluster"
•E0630 00:06:49.362358   10831 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:39645/?timeout=50ms: dial tcp 127.0.0.1:39645: connect: connection refused"  "cluster"="cluster-cache-test-6bbkq/test-cluster"
•E0630 00:06:49.571380   10831 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0630 00:06:49.571439   10831 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-820199426/tls.crt: no such file or directory"  
I0630 00:06:49.571619   10831 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0630 00:06:49.616356   10831 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:44453/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:44453: connect: connection refused


Ran 5 of 5 Specs in 16.994 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.99s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	17.146s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 206 lines ...
=== RUN   TestReconcileNoClusterOwnerRef
I0630 00:06:56.881440   11688 controller.go:129]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.01s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0630 00:06:56.884100   11688 controller.go:125]  "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
I0630 00:06:56.885861   11688 controller.go:135]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0630 00:06:56.886082   11688 controller.go:135]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0630 00:07:14.702337   11688 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
I0630 00:07:14.702479   11688 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: 1625011604
Will run 1 of 1 specs

E0630 00:07:15.072549   11688 controller.go:125]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-fgof02\" not found" "kubeadmControlPlane"="kcp-foo-fgof02" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.367 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.37s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0630 00:07:15.073958   11688 controller.go:244]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-abu8p7" "kubeadmControlPlane"="kcp-foo-abu8p7" "namespace"="test" 
I0630 00:07:17.402265   11688 controller.go:329]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-abu8p7" "kubeadmControlPlane"="kcp-foo-abu8p7" "namespace"="test" "needRollout"=["kcp-foo-abu8p7-bds22"]
I0630 00:07:17.402485   11688 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-abu8p7" "kubeadmControlPlane"="kcp-foo-abu8p7" "namespace"="test" "failures"="[machine kcp-foo-abu8p7-79kjl does not have APIServerPodHealthy condition, machine kcp-foo-abu8p7-79kjl does not have ControllerManagerPodHealthy condition, machine kcp-foo-abu8p7-79kjl does not have SchedulerPodHealthy condition, machine kcp-foo-abu8p7-79kjl does not have EtcdPodHealthy condition, machine kcp-foo-abu8p7-79kjl does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (2.33s)
... skipping 60 lines ...
==================================
Random Seed: 1625011603
Will run 7 of 7 specs

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

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 271 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
E0630 00:06:58.903735   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:07:07.226827   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:07:16.212889   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:07:27.343208   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:07:43.816430   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:07:56.825036   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:08:14.472506   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:08:35.395996   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:09:06.412614   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0630 00:09:51.569925   11622 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 71 lines ...
=== RUN   TestClusterStatus/returns_cluster_status
=== RUN   TestClusterStatus/returns_cluster_status_with_kubeadm_config
--- PASS: TestClusterStatus (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status_with_kubeadm_config (0.00s)
PASS
E0630 00:09:51.576903   11622 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0630 00:09:51.576948   11622 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-042010144/tls.crt: no such file or directory"  
E0630 00:09:51.576971   11622 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0630 00:09:51.576993   11622 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-042010144/tls.crt: no such file or directory"  
I0630 00:09:51.577146   11622 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.688s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.01s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0630 00:07:04.069713   11945 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0630 00:07:04.071032   11945 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0630 00:07:04.171403   11945 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0630 00:07:04.271930   11945 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0630 00:07:04.272028   11945 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0630 00:07:04.357214   11945 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-8d6zuk"} 
•E0630 00:07:04.377769   11945 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"
I0630 00:07:05.437155   11945 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-rqtv9i"} 
E0630 00:07:05.469501   11945 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"
•E0630 00:07:16.554216   11945 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"

------------------------------
• Failure [11.079 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0630 00:07:17.705035   11945 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"
•E0630 00:07:18.732927   11945 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"
•E0630 00:07:19.749207   11945 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0630 00:07:19.749274   11945 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-322732121/tls.crt: no such file or directory"  
E0630 00:07:19.749304   11945 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0630 00:07:19.749328   11945 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-322732121/tls.crt: no such file or directory"  
I0630 00:07:19.749473   11945 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0630 00:07:19.749553   11945 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0630 00:07:19.749626   11945 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0630 00:07:19.752241   11945 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"



Summarizing 1 Failure:

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

Ran 5 of 5 Specs in 28.630 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (28.63s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	28.739s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0630 00:06:56.603038   12123 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 91 lines ...
•I0630 00:07:08.386415   12123 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0630 00:07:08.417426   12123 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0630 00:07:08.433512   12123 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0630 00:07:08.435577   12123 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0630 00:07:08.456343   12123 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0630 00:07:08.472732   12123 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0630 00:07:08.475188   12123 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0630 00:07:08.475255   12123 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-387731893/tls.crt: no such file or directory"  
I0630 00:07:08.475334   12123 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 11.804 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.80s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	12.080s
?   	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 ...
•I0630 00:07:37.188202   15174 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 8.341 seconds
FAIL! -- 13 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestPatch (8.34s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
    --- PASS: TestToUnstructured/with_an_unstructured_object (0.00s)
... skipping 2 lines ...
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields
--- PASS: TestUnsafeFocusedUnstructured (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=spec,_should_only_return_spec_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields (0.00s)
FAIL
FAIL	sigs.k8s.io/cluster-api/util/patch	8.370s
?   	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.014s
... skipping 64 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.042s
FAIL
make: *** [Makefile:116: test] Error 1
+ EXIT_VALUE=2
+ set +o xtrace