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

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0807 15:03:58.757371    8445 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0807 15:03:59.503301    8445 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" 
•I0807 15:03:59.515032    8445 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.196 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.20s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	51.021s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0807 15:03:42.176880   10483 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0807 15:03:42.176939   10483 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0807 15:03:42.177255   10483 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0807 15:03:42.177301   10483 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0807 15:03:42.177353   10483 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0807 15:03:42.177391   10483 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2022/08/07 15:03:42 http: TLS handshake error from 127.0.0.1:51956: 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
I0807 15:03:42.374072   10483 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"
I0807 15:03:42.382989   10483 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
I0807 15:03:42.424657   10483 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
I0807 15:03:42.426545   10483 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"
E0807 15:03:42.426877   10483 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
I0807 15:03:42.427365   10483 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
I0807 15:03:42.726870   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0807 15:03:42.729265   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0807 15:03:42.736498   10483 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0807 15:03:42.736591   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0807 15:03:42.845723   10483 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0807 15:03:42.845820   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0807 15:03:42.946405   10483 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv" "noderef"="node-1"
E0807 15:03:42.956783   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0807 15:03:42.956835   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0807 15:03:42.983209   10483 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv" "noderef"="node-1"
E0807 15:03:43.019548   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-m7rks\" in namespace \"test-machine-watches-fnqvv\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv"
E0807 15:03:44.024549   10483 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-m7rks\" in namespace \"test-machine-watches-fnqvv\", requeuing: requeue in 1s"  
E0807 15:03:44.032737   10483 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-m7rks\" in namespace \"test-machine-watches-fnqvv\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-m7rks\" in namespace \"test-machine-watches-fnqvv\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv"
--- PASS: TestWatches (1.63s)
=== 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
I0807 15:03:44.250028   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-m5pz9" "namespace"="test-machine-watches-fnqvv" "count"=1
I0807 15:03:44.250096   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-m5pz9" "namespace"="test-machine-watches-fnqvv" "descendants"="Worker machines: machine-created-m7rks" "indirect descendants count"=0
I0807 15:03:44.298225   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-m5pz9" "namespace"="test-machine-watches-fnqvv" "count"=1
I0807 15:03:44.298289   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-m5pz9" "namespace"="test-machine-watches-fnqvv" "descendants"="Worker machines: machine-created-m7rks" "indirect descendants count"=0
I0807 15:03:45.033297   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m5pz9" "machine"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"41773917-ab6b-4ccf-9df2-993c62197658","apiVersion":"v1"}
E0807 15:03:45.169015   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-m7rks\" not found" "controller"="machine" "name"="machine-created-m7rks" "namespace"="test-machine-watches-fnqvv"
E0807 15:03:46.217095   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-zwvx8\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-fzrbg\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-fzrbg: secrets \"machine-reconcile-fzrbg-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-zwvx8" "namespace"="default"
I0807 15:03:47.217770   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-fzrbg" "machine"="machine-created-zwvx8" "namespace"="default" "cause"="noderef is nil" "node"=null
I0807 15:03:47.254582   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-fzrbg" "machine"="machine-created-zwvx8" "namespace"="default" "cause"="noderef is nil" "node"=null
I0807 15:03:47.279626   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-fzrbg" "machine"="machine-created-zwvx8" "namespace"="default" "cause"="noderef is nil" "node"=null
E0807 15:03:47.322095   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-zwvx8\" not found" "controller"="machine" "name"="machine-created-zwvx8" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.28s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.28s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 4 lines ...
I0807 15:03:47.338920   10483 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"
I0807 15:03:47.339047   10483 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0807 15:03:47.343256   10483 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"
I0807 15:03:47.343371   10483 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
E0807 15:03:47.358837   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-fzrbg\" not found" "controller"="cluster" "name"="machine-reconcile-fzrbg" "namespace"="default"
I0807 15:03:47.359290   10483 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"
I0807 15:03:47.359417   10483 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.03s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.01s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
... skipping 121 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0807 15:03:47.536072   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z627f" "namespace"="test-mhc-ljqxn" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0807 15:03:47.559842   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0807 15:03:47.561169   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-74fgl\" not found"  "cluster"="test-mhc-ljqxn/test-cluster-74fgl"
E0807 15:03:47.582212   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-z627f\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-z627f\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-z627f" "namespace"="test-mhc-ljqxn"
=== 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
I0807 15:03:48.582581   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z627f" "namespace"="test-mhc-ljqxn" 
I0807 15:03:48.582692   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dz646" "namespace"="test-mhc-wvkbc" 
I0807 15:03:48.582720   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nrkrc" "namespace"="test-mhc-hz4wn" 
I0807 15:03:48.582747   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ff78t" "namespace"="test-mhc-7jk56" 
I0807 15:03:48.603416   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 15:03:48.626145   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ff78t" "namespace"="test-mhc-7jk56" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0807 15:03:48.710896   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ff78t" "namespace"="test-mhc-7jk56" 
E0807 15:03:48.737817   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7jk56/test-cluster-8d6vg"
E0807 15:03:48.739259   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-8d6vg\" not found" "controller"="cluster" "name"="test-cluster-8d6vg" "namespace"="test-mhc-7jk56"
I0807 15:03:48.746605   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prg6p" "namespace"="test-mhc-gfl8q" 
I0807 15:03:48.790416   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 15:03:48.809663   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prg6p" "namespace"="test-mhc-gfl8q" 
I0807 15:03:48.814742   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prg6p" "namespace"="test-mhc-gfl8q" 
E0807 15:03:48.852837   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gfl8q/test-cluster-7cdpv"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0807 15:03:48.862751   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prg6p" "namespace"="test-mhc-gfl8q" 
I0807 15:03:48.884447   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
inframachine created: test-mhc-machine-infra-fdmdz
I0807 15:03:48.914181   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-rx92d
I0807 15:03:48.939212   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:48.949528   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:48.949891   10483 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-78gdj/test-mhc-4cn8v/test-mhc-machine-rx92d/"
E0807 15:03:49.026641   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-65d6k, got []"  "node"="test-mhc-node-65d6k"
node created: test-mhc-node-65d6k
E0807 15:03:49.027022   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-65d6k"
I0807 15:03:49.030348   10483 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-rx92d" "namespace"="test-mhc-78gdj" "noderef"="test-mhc-node-65d6k"
E0807 15:03:49.035234   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-65d6k, got []"  "node"="test-mhc-node-65d6k"
E0807 15:03:49.035286   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-65d6k, got []"  "node"="test-mhc-node-65d6k"
E0807 15:03:49.035511   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-65d6k"
E0807 15:03:49.035538   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-65d6k"
inframachine created: test-mhc-machine-infra-pfl72
machine created: test-mhc-machine-xnhfm
I0807 15:03:49.103095   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.128151   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.129526   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.130765   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
... skipping 39 lines ...
I0807 15:03:49.261756   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.264305   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.269306   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.273794   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.275161   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.284503   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.285207   10483 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-78gdj/test-mhc-4cn8v/test-mhc-machine-xnhfm/"
I0807 15:03:49.316699   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.317125   10483 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-78gdj/test-mhc-4cn8v/test-mhc-machine-xnhfm/"
I0807 15:03:49.341688   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.342204   10483 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-78gdj/test-mhc-4cn8v/test-mhc-machine-xnhfm/"
I0807 15:03:49.357652   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.358210   10483 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-78gdj/test-mhc-4cn8v/test-mhc-machine-xnhfm/"
I0807 15:03:49.366432   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.366899   10483 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-78gdj/test-mhc-4cn8v/test-mhc-machine-xnhfm/"
E0807 15:03:49.382964   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-g8hhm"
node created: test-mhc-node-g8hhm
E0807 15:03:49.383011   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g8hhm, got []"  "node"="test-mhc-node-g8hhm"
I0807 15:03:49.383648   10483 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj" "noderef"="test-mhc-node-g8hhm"
E0807 15:03:49.388842   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g8hhm, got []"  "node"="test-mhc-node-g8hhm"
E0807 15:03:49.388903   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g8hhm, got []"  "node"="test-mhc-node-g8hhm"
E0807 15:03:49.389893   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-g8hhm"
E0807 15:03:49.389940   10483 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-g8hhm"
I0807 15:03:49.402670   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.476235   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
Cleaning up nodes, machines and infra machines.
I0807 15:03:49.482851   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.483607   10483 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-78gdj/test-mhc-4cn8v/test-mhc-machine-rx92d/"
I0807 15:03:49.575995   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:49.576598   10483 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-78gdj/test-mhc-4cn8v/test-mhc-machine-rx92d/"
I0807 15:03:49.577082   10483 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-78gdj/test-mhc-4cn8v/test-mhc-machine-xnhfm/"
I0807 15:03:49.598580   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-5fcw5" "machine"="test-mhc-machine-rx92d" "namespace"="test-mhc-78gdj" "cause"="no control plane members" "node"={"kind":"Node","name":"test-mhc-node-65d6k","uid":"a9227b0c-b3f7-4d00-b295-eb5f0f410217","apiVersion":"v1"}
E0807 15:03:49.603198   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-78gdj/test-cluster-5fcw5"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-mwqhr
machine created: test-mhc-machine-rgmsn
E0807 15:03:49.662978   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rx92d\" not found" "controller"="machine" "name"="test-mhc-machine-rx92d" "namespace"="test-mhc-78gdj"
E0807 15:03:49.752941   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-fnqvv/machine-reconcile-m5pz9"
E0807 15:03:49.807978   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4cn8v\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj"
E0807 15:03:50.663389   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:03:50.808434   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:50.826201   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 15:03:50.889235   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4cn8v" "namespace"="test-mhc-78gdj" 
I0807 15:03:50.889324   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:50.890307   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:50.897750   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
... skipping 366 lines ...
I0807 15:03:51.675831   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.677593   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.679059   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.679629   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.681265   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.683131   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
E0807 15:03:51.684549   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:03:51.684586   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.684820   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-rgmsn/"
I0807 15:03:51.696793   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.697198   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-rgmsn/"
E0807 15:03:51.774193   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xjxd4, got []"  "node"="test-mhc-node-xjxd4"
node created: test-mhc-node-xjxd4
I0807 15:03:51.784639   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
inframachine created: test-mhc-machine-infra-fc5gz
machine created: test-mhc-machine-5rjn2
I0807 15:03:51.824022   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:51.831108   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
... skipping 324 lines ...
I0807 15:03:52.753298   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.755694   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.758237   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.761363   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.764666   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.768294   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
E0807 15:03:52.772516   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:03:52.773576   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.775365   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.777421   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.779366   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.781283   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:52.782910   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
... skipping 249 lines ...
I0807 15:03:53.732421   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.738353   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.740868   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.743820   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.746424   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.783722   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.804050   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-5rjn2/"
E0807 15:03:53.809086   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
E0807 15:03:53.822963   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cmcxh, got []"  "node"="test-mhc-node-cmcxh"
node created: test-mhc-node-cmcxh
I0807 15:03:53.832226   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.832698   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-5rjn2/"
I0807 15:03:53.846848   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
inframachine created: test-mhc-machine-infra-5ljhd
machine created: test-mhc-machine-lrd7h
I0807 15:03:53.874768   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.883850   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:53.886367   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
... skipping 260 lines ...
I0807 15:03:54.855407   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.857269   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.861514   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.864924   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.873151   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.879533   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
E0807 15:03:54.881480   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:03:54.884544   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.887221   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.889789   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.891884   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.894187   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:54.895795   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
... skipping 283 lines ...
I0807 15:03:55.888478   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.893644   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.895501   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.897711   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.900462   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.902833   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.903336   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-lrd7h/"
I0807 15:03:55.914387   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.914989   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-lrd7h/"
I0807 15:03:55.917187   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:55.918541   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-lrd7h/"
E0807 15:03:55.921858   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
E0807 15:03:55.988900   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4gsjz, got []"  "node"="test-mhc-node-4gsjz"
node created: test-mhc-node-4gsjz
I0807 15:03:56.006295   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:56.006905   10483 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-tl5db/test-mhc-pw82j/test-mhc-machine-lrd7h/test-mhc-node-4gsjz"
Cleaning up nodes, machines and infra machines.
I0807 15:03:56.018281   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pw82j" "namespace"="test-mhc-tl5db" 
I0807 15:03:56.018960   10483 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-tl5db/test-mhc-pw82j/test-mhc-machine-lrd7h/"
Cleaning up nodes, machines and infra machines.
I0807 15:03:56.072189   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-bmbwv" "namespace"="test-mhc-tl5db" "count"=2
I0807 15:03:56.072270   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-bmbwv" "namespace"="test-mhc-tl5db" "descendants"="Worker machines: test-mhc-machine-rgmsn,test-mhc-machine-5rjn2,test-mhc-machine-lrd7h" "indirect descendants count"=1
I0807 15:03:56.078180   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-bmbwv" "namespace"="test-mhc-tl5db" "count"=2
I0807 15:03:56.078245   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-bmbwv" "namespace"="test-mhc-tl5db" "descendants"="Worker machines: test-mhc-machine-lrd7h,test-mhc-machine-rgmsn,test-mhc-machine-5rjn2" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
... skipping 8 lines ...
I0807 15:03:56.312625   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:03:56.353618   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:03:56.434938   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:03:56.596040   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:03:56.917145   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:03:56.922318   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-bmbwv" "machine"="test-mhc-machine-lrd7h" "namespace"="test-mhc-tl5db" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4gsjz"}
E0807 15:03:57.010362   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lrd7h\" not found" "controller"="machine" "name"="test-mhc-machine-lrd7h" "namespace"="test-mhc-tl5db"
I0807 15:03:57.558394   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:03:58.010958   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-bmbwv" "machine"="test-mhc-machine-5rjn2" "namespace"="test-mhc-tl5db" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-cmcxh"}
E0807 15:03:58.085111   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5rjn2\" not found" "controller"="machine" "name"="test-mhc-machine-5rjn2" "namespace"="test-mhc-tl5db"
I0807 15:03:58.839501   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:03:59.085742   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-bmbwv" "machine"="test-mhc-machine-rgmsn" "namespace"="test-mhc-tl5db" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xjxd4"}
E0807 15:03:59.140188   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rgmsn\" not found" "controller"="machine" "name"="test-mhc-machine-rgmsn" "namespace"="test-mhc-tl5db"
E0807 15:04:00.140615   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
E0807 15:04:01.102425   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tl5db/test-cluster-bmbwv"
I0807 15:04:01.151240   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:01.155004   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
E0807 15:04:01.156561   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
node created: test-mhc-node-sn8q5
E0807 15:04:01.184102   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sn8q5, got []"  "node"="test-mhc-node-sn8q5"
inframachine created: test-mhc-machine-infra-gcrj4
I0807 15:04:01.204998   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
machine created: test-mhc-machine-28b2z
I0807 15:04:01.225551   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:01.357350   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:01.363937   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
... skipping 4 lines ...
I0807 15:04:01.901822   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:02.173475   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:02.182123   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:02.192351   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:02.206183   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:02.216281   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
E0807 15:04:02.223244   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:04:02.223415   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:02.254136   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
E0807 15:04:02.323519   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-b6ghj, got []"  "node"="test-mhc-node-b6ghj"
node created: test-mhc-node-b6ghj
I0807 15:04:02.334401   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
inframachine created: test-mhc-machine-infra-w7ljv
I0807 15:04:02.348209   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:02.351146   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
machine created: test-mhc-machine-cv8zg
... skipping 5 lines ...
I0807 15:04:03.284038   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:03.293533   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:03.299188   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:03.313428   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:03.321487   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:03.360455   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
E0807 15:04:03.373575   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tqfcj, got []"  "node"="test-mhc-node-tqfcj"
node created: test-mhc-node-tqfcj
I0807 15:04:03.379948   10483 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-cv8zg" "namespace"="test-mhc-wqhjl" "noderef"="test-mhc-node-tqfcj"
E0807 15:04:03.388831   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tqfcj, got []"  "node"="test-mhc-node-tqfcj"
E0807 15:04:03.388883   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tqfcj, got []"  "node"="test-mhc-node-tqfcj"
Cleaning up nodes, machines and infra machines.
I0807 15:04:03.389227   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:03.419741   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7kbxh" "machine"="test-mhc-machine-28b2z" "namespace"="test-mhc-wqhjl" "cause"="no control plane members" "node"={"name":"test-mhc-node-b6ghj"}
Cleaning up nodes, machines and infra machines.
I0807 15:04:03.451017   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7kbxh" "namespace"="test-mhc-wqhjl" "count"=3
I0807 15:04:03.451119   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7kbxh" "namespace"="test-mhc-wqhjl" "descendants"="Worker machines: test-mhc-machine-6dhg2,test-mhc-machine-28b2z,test-mhc-machine-cv8zg" "indirect descendants count"=0
I0807 15:04:03.456912   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7kbxh" "namespace"="test-mhc-wqhjl" "count"=3
I0807 15:04:03.457585   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7kbxh" "namespace"="test-mhc-wqhjl" "descendants"="Worker machines: test-mhc-machine-6dhg2,test-mhc-machine-28b2z,test-mhc-machine-cv8zg" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
E0807 15:04:03.472924   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-28b2z\" not found" "controller"="machine" "name"="test-mhc-machine-28b2z" "namespace"="test-mhc-wqhjl"
inframachine created: test-mhc-machine-infra-42rzp
machine created: test-mhc-machine-4wj75
I0807 15:04:03.574077   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:03.592728   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 15:04:03.722991   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zkr4l" "namespace"="test-mhc-wqhjl" 
I0807 15:04:03.723064   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:04.473471   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7kbxh" "machine"="test-mhc-machine-cv8zg" "namespace"="test-mhc-wqhjl" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-tqfcj","uid":"a01e3116-f57f-4012-b9d5-bc46a1045895","apiVersion":"v1"}
E0807 15:04:04.532835   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cv8zg\" not found" "controller"="machine" "name"="test-mhc-machine-cv8zg" "namespace"="test-mhc-wqhjl"
I0807 15:04:05.540576   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7kbxh" "machine"="test-mhc-machine-6dhg2" "namespace"="test-mhc-wqhjl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-sn8q5"}
E0807 15:04:05.610366   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6dhg2\" not found" "controller"="machine" "name"="test-mhc-machine-6dhg2" "namespace"="test-mhc-wqhjl"
E0807 15:04:06.612503   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:04:07.623272   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.627632   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.650127   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
node created: test-mhc-node-9757f
E0807 15:04:07.651712   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9757f, got []"  "node"="test-mhc-node-9757f"
E0807 15:04:07.651921   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9757f, got []"  "node"="test-mhc-node-9757f"
I0807 15:04:07.673405   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
inframachine created: test-mhc-machine-infra-mvkl2
machine created: test-mhc-machine-smqh8
I0807 15:04:07.695346   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.712626   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.717013   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.724788   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.740638   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.759058   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.775567   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.783134   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:07.794013   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
E0807 15:04:07.796769   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wvdwr, got []"  "node"="test-mhc-node-wvdwr"
node created: test-mhc-node-wvdwr
E0807 15:04:07.796956   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wvdwr, got []"  "node"="test-mhc-node-wvdwr"
I0807 15:04:07.803255   10483 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-smqh8" "namespace"="test-mhc-bjn9x" "noderef"="test-mhc-node-wvdwr"
I0807 15:04:07.805736   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
inframachine created: test-mhc-machine-infra-942nb
I0807 15:04:07.823689   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
machine created: test-mhc-machine-7vrvz
I0807 15:04:07.830641   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
... skipping 10 lines ...
I0807 15:04:08.036481   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:08.043823   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-65nl6" "machine"="test-mhc-machine-7vrvz" "namespace"="test-mhc-bjn9x" "cause"="noderef is nil" "node"=null
Cleaning up nodes, machines and infra machines.
I0807 15:04:08.053457   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:08.057618   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:08.060077   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:08.060763   10483 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bjn9x/test-mhc-sns66/test-mhc-machine-4wj75/"
E0807 15:04:08.106867   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7vrvz\" not found" "controller"="machine" "name"="test-mhc-machine-7vrvz" "namespace"="test-mhc-bjn9x"
I0807 15:04:08.119682   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-65nl6" "namespace"="test-mhc-bjn9x" "count"=2
I0807 15:04:08.119761   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-65nl6" "namespace"="test-mhc-bjn9x" "descendants"="Worker machines: test-mhc-machine-4wj75,test-mhc-machine-smqh8" "indirect descendants count"=0
I0807 15:04:08.125278   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-65nl6" "namespace"="test-mhc-bjn9x" "count"=2
I0807 15:04:08.125336   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-65nl6" "namespace"="test-mhc-bjn9x" "descendants"="Worker machines: test-mhc-machine-4wj75,test-mhc-machine-smqh8" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-5nnwg
machine created: test-mhc-machine-sddgs
E0807 15:04:08.268121   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-sns66\" not found" "controller"="machinehealthcheck" "name"="test-mhc-sns66" "namespace"="test-mhc-bjn9x"
E0807 15:04:08.474745   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wqhjl/test-cluster-7kbxh"
I0807 15:04:09.107412   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-65nl6" "machine"="test-mhc-machine-4wj75" "namespace"="test-mhc-bjn9x" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9757f"}
E0807 15:04:09.160123   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4wj75\" not found" "controller"="machine" "name"="test-mhc-machine-4wj75" "namespace"="test-mhc-bjn9x"
I0807 15:04:09.268469   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:09.287755   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 15:04:09.336616   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sns66" "namespace"="test-mhc-bjn9x" 
I0807 15:04:09.336690   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:09.345239   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:09.346255   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
... skipping 372 lines ...
I0807 15:04:10.205529   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.207204   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.209160   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.210889   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.212639   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.214288   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
E0807 15:04:10.215445   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-smqh8\" not found" "controller"="machine" "name"="test-mhc-machine-smqh8" "namespace"="test-mhc-bjn9x"
I0807 15:04:10.216023   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.217785   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.219502   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.221219   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.222996   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:10.224786   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
... skipping 453 lines ...
I0807 15:04:11.219584   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.221248   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.222906   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.223765   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.224573   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.226290   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
E0807 15:04:11.226907   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:04:11.227343   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.227617   10483 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-qrcj2/test-mhc-6qcts/test-mhc-machine-sddgs/"
I0807 15:04:11.240007   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.240369   10483 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-qrcj2/test-mhc-6qcts/test-mhc-machine-sddgs/"
node created: test-mhc-node-79svl
E0807 15:04:11.305322   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-79svl, got []"  "node"="test-mhc-node-79svl"
E0807 15:04:11.305322   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-79svl, got []"  "node"="test-mhc-node-79svl"
I0807 15:04:11.312731   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.332136   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.333134   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.336224   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.336517   10483 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-qrcj2/test-mhc-6qcts/test-mhc-machine-sddgs/test-mhc-node-79svl"
I0807 15:04:11.350627   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.351049   10483 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-qrcj2/test-mhc-6qcts/test-mhc-machine-sddgs/test-mhc-node-79svl"
Cleaning up nodes, machines and infra machines.
I0807 15:04:11.361221   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.361553   10483 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qrcj2/test-mhc-6qcts/test-mhc-machine-sddgs/"
I0807 15:04:11.390104   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rxc2k" "namespace"="test-mhc-qrcj2" "descendants"="Worker machines: test-mhc-machine-sddgs" "indirect descendants count"=1
I0807 15:04:11.397410   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rxc2k" "namespace"="test-mhc-qrcj2" "descendants"="Worker machines: test-mhc-machine-sddgs" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0807 15:04:11.527263   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6qcts" "namespace"="test-mhc-qrcj2" 
I0807 15:04:11.537419   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" "creating"=1 "need"=1
I0807 15:04:11.537476   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
I0807 15:04:11.551259   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-cv5g2-mpxz6\"" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
I0807 15:04:11.600584   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:11.619465   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 15:04:11.643011   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:12.227435   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rxc2k" "machine"="test-mhc-machine-sddgs" "namespace"="test-mhc-qrcj2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-79svl"}
E0807 15:04:12.313260   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-sddgs\" not found" "controller"="machine" "name"="test-mhc-machine-sddgs" "namespace"="test-mhc-qrcj2"
I0807 15:04:12.643220   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
E0807 15:04:13.139261   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-bjn9x/test-cluster-65nl6"
I0807 15:04:13.324638   10483 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
I0807 15:04:13.324798   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:13.328611   10483 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
I0807 15:04:13.328764   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:13.341624   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:13.341687   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
... skipping 4 lines ...
I0807 15:04:13.366303   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:13.366360   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:13.647357   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:14.366774   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:14.366828   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:15.000693   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:15.001185   10483 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-znj97/test-mhc-qgzxx/mhc-ms-cv5g2-mpxz6/"
I0807 15:04:15.014818   10483 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
I0807 15:04:15.019862   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:15.019917   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:15.020989   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:15.021331   10483 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-znj97/test-mhc-qgzxx/mhc-ms-cv5g2-mpxz6/"
I0807 15:04:15.044564   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:15.044980   10483 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-znj97/test-mhc-qgzxx/mhc-ms-cv5g2-mpxz6/"
I0807 15:04:15.050435   10483 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" "machine"="mhc-ms-cv5g2-mpxz6"
I0807 15:04:15.052735   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "count"=1
I0807 15:04:15.052792   10483 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-cv5g2"
I0807 15:04:15.056913   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:15.057285   10483 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-znj97/test-mhc-qgzxx/mhc-ms-cv5g2-mpxz6/"
I0807 15:04:15.062731   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "descendants"="Machine sets: mhc-ms-cv5g2;Worker machines: mhc-ms-cv5g2-mpxz6" "indirect descendants count"=1
I0807 15:04:15.064831   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:15.064879   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" 
I0807 15:04:15.065971   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-w6xrd" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" "cause"="cluster is being deleted" "node"=null
I0807 15:04:15.067460   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
I0807 15:04:15.067787   10483 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-znj97/test-mhc-qgzxx/mhc-ms-cv5g2-mpxz6/"
I0807 15:04:15.071190   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "count"=1
I0807 15:04:15.071248   10483 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-cv5g2"
E0807 15:04:15.073872   10483 cluster_controller.go:244] controllers/Cluster "msg"="Error deleting resource" "error"="error deleting cluster test-mhc-znj97/test-cluster-w6xrd: failed to delete cluster.x-k8s.io/v1alpha3, Kind=MachineSet mhc-ms-cv5g2: machinesets.cluster.x-k8s.io \"mhc-ms-cv5g2\" not found" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-cv5g2"
I0807 15:04:15.073989   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" "creating"=1 "need"=1
I0807 15:04:15.074054   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
E0807 15:04:15.074227   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="error deleting cluster test-mhc-znj97/test-cluster-w6xrd: failed to delete cluster.x-k8s.io/v1alpha3, Kind=MachineSet mhc-ms-cv5g2: machinesets.cluster.x-k8s.io \"mhc-ms-cv5g2\" not found" "controller"="cluster" "name"="test-cluster-w6xrd" "namespace"="test-mhc-znj97"
I0807 15:04:15.089909   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qgzxx" "namespace"="test-mhc-znj97" 
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0807 15:04:15.109084   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-cv5g2-p6jhr\"" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
E0807 15:04:15.115736   10483 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-cv5g2\" not found" "machineset"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97" 
E0807 15:04:15.115854   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-cv5g2\" not found" "controller"="machineset" "name"="mhc-ms-cv5g2" "namespace"="test-mhc-znj97"
I0807 15:04:15.209558   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
inframachine created: test-mhc-machine-infra-ddjr7
I0807 15:04:15.231313   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-6xxf9
I0807 15:04:15.295585   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-w6xrd" "machine"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97" "cause"="cluster is being deleted" "node"=null
E0807 15:04:15.331302   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-cv5g2-mpxz6\" not found" "controller"="machine" "name"="mhc-ms-cv5g2-mpxz6" "namespace"="test-mhc-znj97"
E0807 15:04:15.340921   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wzps6, got []"  "node"="test-mhc-node-wzps6"
E0807 15:04:15.341002   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wzps6, got []"  "node"="test-mhc-node-wzps6"
E0807 15:04:15.341122   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wzps6, got []"  "node"="test-mhc-node-wzps6"
node created: test-mhc-node-wzps6
I0807 15:04:15.411080   10483 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-6xxf9" "target"="test-mhc-vhmc5/test-mhc-qnpfb/test-mhc-machine-6xxf9/"
I0807 15:04:15.446979   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
I0807 15:04:15.486042   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
I0807 15:04:15.495814   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
I0807 15:04:15.500983   10483 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-6xxf9" "target"="test-mhc-vhmc5/test-mhc-qnpfb/test-mhc-machine-6xxf9/test-mhc-node-wzps6"
I0807 15:04:15.537281   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
Cleaning up nodes, machines and infra machines.
I0807 15:04:15.554773   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
I0807 15:04:15.558640   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
I0807 15:04:15.562403   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
E0807 15:04:15.574582   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vhmc5/test-cluster-qfknm"
I0807 15:04:15.581611   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qnpfb" "namespace"="test-mhc-vhmc5" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0807 15:04:15.716921   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
inframachine created: test-mhc-machine-infra-s64m5
I0807 15:04:15.734675   10483 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-7cl8p
... skipping 207 lines ...
I0807 15:04:16.351739   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.353668   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.355543   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.357753   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.359539   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.362033   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
E0807 15:04:16.362336   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
I0807 15:04:16.364201   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.366135   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.368038   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.370003   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.371884   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.373816   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
... skipping 11 lines ...
I0807 15:04:16.401985   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.403625   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.407070   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.408965   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.410788   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.413606   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
E0807 15:04:16.413752   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qrcj2/test-cluster-rxc2k"
I0807 15:04:16.415555   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.417430   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.419281   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.421137   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.423524   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:16.429235   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
... skipping 417 lines ...
I0807 15:04:17.384374   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.386294   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.388688   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.390486   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.391563   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.392235   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
E0807 15:04:17.392304   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
I0807 15:04:17.397035   10483 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-7cl8p" "target"="test-mhc-9vs6b/test-mhc-dwhlt/test-mhc-machine-7cl8p/"
I0807 15:04:17.413337   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
E0807 15:04:17.464100   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-f6b45, got []"  "node"="test-mhc-node-f6b45"
node created: test-mhc-node-f6b45
E0807 15:04:17.464412   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-f6b45, got []"  "node"="test-mhc-node-f6b45"
I0807 15:04:17.474566   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.508809   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.524949   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.532823   10483 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-7cl8p" "target"="test-mhc-9vs6b/test-mhc-dwhlt/test-mhc-machine-7cl8p/test-mhc-node-f6b45"
I0807 15:04:17.559294   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.576340   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.605873   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
Cleaning up nodes, machines and infra machines.
I0807 15:04:17.622579   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
I0807 15:04:17.628133   10483 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-7cl8p" "target"="test-mhc-9vs6b/test-mhc-dwhlt/test-mhc-machine-7cl8p/"
I0807 15:04:17.645804   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ghzg7" "namespace"="test-mhc-9vs6b" "descendants"="Worker machines: test-mhc-machine-7cl8p" "indirect descendants count"=1
I0807 15:04:17.660292   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ghzg7" "namespace"="test-mhc-9vs6b" "descendants"="Worker machines: test-mhc-machine-7cl8p" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (30.17s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.05s)
... skipping 12 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.49s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.08s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0807 15:04:17.670182   10483 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
E0807 15:04:17.671612   10483 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
E0807 15:04:17.675129   10483 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0807 15:04:17.675299   10483 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
E0807 15:04:17.675619   10483 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
E0807 15:04:17.676983   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-dwhlt\" not found" "controller"="machinehealthcheck" "name"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b"
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_two_Machines_exist_for_the_Node (0.00s)
... skipping 29 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
I0807 15:04:17.679181   10483 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0807 15:04:17.679576   10483 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0807 15:04:17.682154   10483 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
E0807 15:04:17.693910   10483 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
E0807 15:04:17.696095   10483 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 ...
I0807 15:04:17.718535   10483 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"
•I0807 15:04:17.720478   10483 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"
I0807 15:04:17.721376   10483 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"
I0807 15:04:17.722363   10483 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0807 15:04:17.722400   10483 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0807 15:04:17.723148   10483 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0807 15:04:17.724901   10483 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" 
••E0807 15:04:17.874750   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-wfw27\" not found" "controller"="cluster" "name"="test1-wfw27" "namespace"="default"
I0807 15:04:18.398517   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:18.398579   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
E0807 15:04:18.399237   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
I0807 15:04:18.677258   10483 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwhlt" "namespace"="test-mhc-9vs6b" 
•I0807 15:04:19.042369   10483 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-j5xjw" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0807 15:04:19.279946   10483 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-j5xjw" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0807 15:04:19.286382   10483 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-j5xjw" "namespace"="default"
I0807 15:04:19.399732   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ghzg7" "machine"="test-mhc-machine-7cl8p" "namespace"="test-mhc-9vs6b" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-f6b45"}
E0807 15:04:19.456763   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7cl8p\" not found" "controller"="machine" "name"="test-mhc-machine-7cl8p" "namespace"="test-mhc-9vs6b"
E0807 15:04:20.310076   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"
•E0807 15:04:20.457214   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
E0807 15:04:21.341626   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-c9vjw\" not found" "controller"="cluster" "name"="test3-c9vjw" "namespace"="default"
I0807 15:04:21.462864   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:21.462940   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
E0807 15:04:21.463610   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
E0807 15:04:22.342446   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"
E0807 15:04:22.463896   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
I0807 15:04:23.356274   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "descendants"="Worker machines: mhc-ms-cv5g2-p6jhr" "indirect descendants count"=1
E0807 15:04:23.356938   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"
•I0807 15:04:23.481516   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:23.481580   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
E0807 15:04:23.482245   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
E0807 15:04:24.370927   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9vs6b/test-cluster-ghzg7"
E0807 15:04:24.375548   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-jr56z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-jr56z" "namespace"="default"
E0807 15:04:24.482540   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
E0807 15:04:25.376873   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"
I0807 15:04:25.496966   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:25.497022   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
E0807 15:04:25.497712   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
E0807 15:04:26.392779   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-jr56z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-jr56z" "namespace"="default"
•E0807 15:04:26.504658   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
E0807 15:04:27.396846   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"
I0807 15:04:27.509844   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:27.509944   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
E0807 15:04:27.632801   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5fcw5\" for machine \"test-mhc-machine-xnhfm\" in namespace \"test-mhc-78gdj\": Cluster.cluster.x-k8s.io \"test-cluster-5fcw5\" not found" "controller"="machine" "name"="test-mhc-machine-xnhfm" "namespace"="test-mhc-78gdj"
E0807 15:04:28.397713   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-jr56z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-jr56z" "namespace"="default"
E0807 15:04:28.633293   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
E0807 15:04:29.408685   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"
E0807 15:04:29.473686   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node id-node-1, got []"  "node"="id-node-1"
I0807 15:04:29.638429   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:29.638495   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:29.669143   10483 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-xtqsx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0807 15:04:29.683288   10483 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-xtqsx" "namespace"="default" 
E0807 15:04:29.710589   10483 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-xtqsx" "namespace"="default"
I0807 15:04:30.409134   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-w6xrd" "namespace"="test-mhc-znj97" "descendants"="Worker machines: mhc-ms-cv5g2-p6jhr" "indirect descendants count"=1
E0807 15:04:30.409577   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-jr56z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-jr56z" "namespace"="default"
I0807 15:04:30.732682   10483 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-xtqsx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0807 15:04:30.732896   10483 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-xtqsx" "namespace"="default" "noderef"="id-node-1"
E0807 15:04:30.737685   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node id-node-1, got []"  "node"="id-node-1"
E0807 15:04:30.737727   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node id-node-1, got []"  "node"="id-node-1"
E0807 15:04:30.747075   10483 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-xtqsx" "namespace"="default"
E0807 15:04:31.414172   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"

------------------------------
• [SLOW TEST:5.059 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 7 lines ...
I0807 15:04:31.724521   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-qxmzx" "namespace"="ms-test" "creating"=1 "need"=2
I0807 15:04:31.724580   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-qxmzx" "namespace"="ms-test" 
I0807 15:04:31.739002   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-qxmzx-d5cm8\"" "machineset"="ms-qxmzx" "namespace"="ms-test" 
I0807 15:04:31.751811   10483 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:31.751905   10483 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-cv5g2-p6jhr" "namespace"="test-mhc-znj97" 
I0807 15:04:31.752666   10483 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-j6svs" "machine"="test6-xtqsx" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"d10fba1c-606b-46e6-a354-b205103537c9","apiVersion":"v1"}
E0807 15:04:31.773565   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-xtqsx\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-xtqsx" "namespace"="default"
E0807 15:04:31.838287   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-qxmzx-d5cm8-jlp68, got []"  "node"="ms-qxmzx-d5cm8-jlp68"
E0807 15:04:31.942772   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-qxmzx-d5cm8-jlp68, got []"  "node"="ms-qxmzx-d5cm8-jlp68"
E0807 15:04:31.942835   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-qxmzx-d5cm8-jlp68, got []"  "node"="ms-qxmzx-d5cm8-jlp68"
E0807 15:04:31.984261   10483 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-qxmzx-d5cm8-jlp68 for machine ms-test/ms-qxmzx-d5cm8: the cache is not started, can not read objects" "machineset"="ms-qxmzx" "namespace"="ms-test" 
E0807 15:04:31.990112   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-qxmzx-cp528-f58vn, got []"  "node"="ms-qxmzx-cp528-f58vn"
E0807 15:04:32.094382   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-qxmzx-cp528-f58vn, got []"  "node"="ms-qxmzx-cp528-f58vn"
E0807 15:04:32.094554   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-qxmzx-cp528-f58vn, got []"  "node"="ms-qxmzx-cp528-f58vn"
E0807 15:04:32.218432   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0807 15:04:32.276731   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0807 15:04:32.276786   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.287857   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-6ft5s-6657c7fddb-pz9mt\"" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.287935   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.303225   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-6ft5s-6657c7fddb-dlfkx\"" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.368721   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0807 15:04:32.368791   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.383950   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-6ft5s-6657c7fddb-xlxsp\"" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.384059   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.400965   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-6ft5s-6657c7fddb-69w8z\"" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
E0807 15:04:32.415111   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-jr56z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-jr56z" "namespace"="default"
I0807 15:04:32.478637   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0807 15:04:32.478679   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.492412   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6ft5s-6657c7fddb-pwzz2\"" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" 
I0807 15:04:32.600875   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0807 15:04:32.600916   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" 
I0807 15:04:32.616257   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6ft5s-cdfc6fd6c-gp5h2\"" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" 
E0807 15:04:32.682410   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-gp5h2-jdmsk, got []"  "node"="md-6ft5s-cdfc6fd6c-gp5h2-jdmsk"
E0807 15:04:32.685590   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-gp5h2-jdmsk, got []"  "node"="md-6ft5s-cdfc6fd6c-gp5h2-jdmsk"
E0807 15:04:32.685733   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-gp5h2-jdmsk, got []"  "node"="md-6ft5s-cdfc6fd6c-gp5h2-jdmsk"
E0807 15:04:32.718154   10483 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-6ft5s-cdfc6fd6c-gp5h2-jdmsk for machine md-test/md-6ft5s-cdfc6fd6c-gp5h2: the cache is not started, can not read objects" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" 
I0807 15:04:32.747349   10483 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0807 15:04:32.747402   10483 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0807 15:04:32.751917   10483 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "machine"="md-6ft5s-6657c7fddb-xlxsp"
I0807 15:04:32.773367   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0807 15:04:32.773411   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" 
E0807 15:04:32.773928   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qfknm\" for machine \"test-mhc-machine-6xxf9\" in namespace \"test-mhc-vhmc5\": Cluster.cluster.x-k8s.io \"test-cluster-qfknm\" not found" "controller"="machine" "name"="test-mhc-machine-6xxf9" "namespace"="test-mhc-vhmc5"
I0807 15:04:32.783144   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6ft5s-cdfc6fd6c-qglhs\"" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" 
E0807 15:04:32.825152   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-qglhs-v4kkg, got []"  "node"="md-6ft5s-cdfc6fd6c-qglhs-v4kkg"
E0807 15:04:32.830588   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-qglhs-v4kkg, got []"  "node"="md-6ft5s-cdfc6fd6c-qglhs-v4kkg"
E0807 15:04:32.830657   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-qglhs-v4kkg, got []"  "node"="md-6ft5s-cdfc6fd6c-qglhs-v4kkg"
I0807 15:04:32.878911   10483 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0807 15:04:32.878951   10483 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0807 15:04:32.884256   10483 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "machine"="md-6ft5s-6657c7fddb-69w8z"
I0807 15:04:32.904147   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0807 15:04:32.904241   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" 
I0807 15:04:32.914557   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6ft5s-cdfc6fd6c-rl75x\"" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" 
E0807 15:04:32.971822   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-rl75x-x866k, got []"  "node"="md-6ft5s-cdfc6fd6c-rl75x-x866k"
E0807 15:04:33.075997   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-rl75x-x866k, got []"  "node"="md-6ft5s-cdfc6fd6c-rl75x-x866k"
E0807 15:04:33.076062   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-cdfc6fd6c-rl75x-x866k, got []"  "node"="md-6ft5s-cdfc6fd6c-rl75x-x866k"
I0807 15:04:33.121861   10483 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0807 15:04:33.121917   10483 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0807 15:04:33.128272   10483 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6ft5s-6657c7fddb" "namespace"="md-test" "machine"="md-6ft5s-6657c7fddb-pwzz2"
I0807 15:04:33.266435   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0807 15:04:33.266476   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" 
I0807 15:04:33.277038   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6ft5s-74d45c49c5-6qblw\"" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" 
E0807 15:04:33.363221   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-6qblw-xvmr4, got []"  "node"="md-6ft5s-74d45c49c5-6qblw-xvmr4"
I0807 15:04:33.415861   10483 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-j6svs" "namespace"="default" "count"=1
I0807 15:04:33.415953   10483 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-j6svs" "namespace"="default" "descendants"="Control plane machines: test6-xtqsx" "indirect descendants count"=0
E0807 15:04:33.420747   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-j5xjw: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-j5xjw" "namespace"="default"
E0807 15:04:33.466947   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-6qblw-xvmr4, got []"  "node"="md-6ft5s-74d45c49c5-6qblw-xvmr4"
E0807 15:04:33.467006   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-6qblw-xvmr4, got []"  "node"="md-6ft5s-74d45c49c5-6qblw-xvmr4"
I0807 15:04:33.506261   10483 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0807 15:04:33.506305   10483 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0807 15:04:33.511182   10483 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "machine"="md-6ft5s-cdfc6fd6c-qglhs"
I0807 15:04:33.621712   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0807 15:04:33.621756   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" 
I0807 15:04:33.630834   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6ft5s-74d45c49c5-xwrqj\"" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" 
E0807 15:04:33.700606   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-xwrqj-tl6zv, got []"  "node"="md-6ft5s-74d45c49c5-xwrqj-tl6zv"
E0807 15:04:33.703974   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-xwrqj-tl6zv, got []"  "node"="md-6ft5s-74d45c49c5-xwrqj-tl6zv"
E0807 15:04:33.704034   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-xwrqj-tl6zv, got []"  "node"="md-6ft5s-74d45c49c5-xwrqj-tl6zv"
I0807 15:04:33.742940   10483 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0807 15:04:33.742985   10483 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0807 15:04:33.746956   10483 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "machine"="md-6ft5s-cdfc6fd6c-rl75x"
E0807 15:04:33.774496   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-qxmzx-cp528\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-qxmzx-cp528" "namespace"="ms-test"
I0807 15:04:33.857491   10483 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0807 15:04:33.857536   10483 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" 
I0807 15:04:33.867596   10483 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6ft5s-74d45c49c5-ppkb4\"" "machineset"="md-6ft5s-74d45c49c5" "namespace"="md-test" 
E0807 15:04:33.966749   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-ppkb4-qj5dq, got []"  "node"="md-6ft5s-74d45c49c5-ppkb4-qj5dq"
E0807 15:04:33.969791   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-ppkb4-qj5dq, got []"  "node"="md-6ft5s-74d45c49c5-ppkb4-qj5dq"
E0807 15:04:33.969842   10483 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-6ft5s-74d45c49c5-ppkb4-qj5dq, got []"  "node"="md-6ft5s-74d45c49c5-ppkb4-qj5dq"
I0807 15:04:34.013443   10483 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0807 15:04:34.013484   10483 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0807 15:04:34.018760   10483 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6ft5s-cdfc6fd6c" "namespace"="md-test" "machine"="md-6ft5s-cdfc6fd6c-gp5h2"
E0807 15:04:34.021465   10483 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
E0807 15:04:34.022315   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-6ft5s\" not found" "controller"="machinedeployment" "name"="md-6ft5s" "namespace"="md-test"
E0807 15:04:34.027494   10483 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machineset" "name"="md-6ft5s-cdfc6fd6c" "namespace"="md-test"
•

Ran 16 of 16 Specs in 16.330 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.33s)
PASS
Tearing down test suite
I0807 15:04:34.028220   10483 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0807 15:04:34.028309   10483 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0807 15:04:34.028347   10483 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0807 15:04:34.028366   10483 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0807 15:04:34.028376   10483 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
I0807 15:04:34.028386   10483 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0807 15:04:34.028432   10483 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
E0807 15:04:34.028447   10483 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-504233515/tls.crt: no such file or directory"  
I0807 15:04:34.028547   10483 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
E0807 15:04:34.059016   10483 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:43539/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1217&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:43539: connect: connection refused
E0807 15:04:34.059053   10483 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:43539/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1217&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:43539: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	65.200s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0807 15:03:44.126175   10939 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0807 15:03:44.126188   10939 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0807 15:03:44.126629   10939 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0807 15:03:44.144534   10939 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0807 15:03:44.144767   10939 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=40885
I0807 15:03:44.145150   10939 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0807 15:03:46.372749   10939 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-hlwz9/test-cluster"
•E0807 15:03:46.845242   10939 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-csvmb/test-cluster"
•E0807 15:03:47.410195   10939 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:43803/?timeout=50ms: dial tcp 127.0.0.1:43803: connect: connection refused"  "cluster"="cluster-cache-test-x7mqt/test-cluster"
•I0807 15:03:47.656469   10939 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0807 15:03:47.756910   10939 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0807 15:03:47.756995   10939 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0807 15:03:47.934166   10939 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0807 15:03:47.954160   10939 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":{}}}
I0807 15:03:48.254592   10939 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0807 15:03:48.254659   10939 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0807 15:03:48.254753   10939 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0807 15:03:48.803505   10939 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0807 15:03:48.803740   10939 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0807 15:03:48.803941   10939 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 15:03:48.803987   10939 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-135690611/tls.crt: no such file or directory"  
E0807 15:03:48.844824   10939 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:33989/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:33989: connect: connection refused


Ran 5 of 5 Specs in 17.596 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (17.60s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	17.753s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 208 lines ...
=== RUN   TestReconcileNoClusterOwnerRef
I0807 15:03:56.325585   11641 controller.go:130]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0807 15:03:56.326800   11641 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0807 15:03:56.327384   11641 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0807 15:03:56.327517   11641 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0807 15:04:15.493485   11641 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
I0807 15:04:15.493654   11641 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: 1659884622
Will run 1 of 1 specs

E0807 15:04:15.538093   11641 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-o7srpg\" not found" "kubeadmControlPlane"="kcp-foo-o7srpg" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.040 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.04s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0807 15:04:15.540135   11641 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-57os76" "kubeadmControlPlane"="kcp-foo-57os76" "namespace"="test" 
I0807 15:04:17.499249   11641 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-57os76" "kubeadmControlPlane"="kcp-foo-57os76" "namespace"="test" "needRollout"=["kcp-foo-57os76-kdqwg"]
I0807 15:04:17.499454   11641 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-57os76" "kubeadmControlPlane"="kcp-foo-57os76" "namespace"="test" "failures"="[machine kcp-foo-57os76-cc4ck does not have APIServerPodHealthy condition, machine kcp-foo-57os76-cc4ck does not have ControllerManagerPodHealthy condition, machine kcp-foo-57os76-cc4ck does not have SchedulerPodHealthy condition, machine kcp-foo-57os76-cc4ck does not have EtcdPodHealthy condition, machine kcp-foo-57os76-cc4ck does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.96s)
PASS
E0807 15:04:17.500775   11641 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0807 15:04:17.500849   11641 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-037037481/tls.crt: no such file or directory"  
E0807 15:04:17.500878   11641 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0807 15:04:17.500899   11641 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-037037481/tls.crt: no such file or directory"  
I0807 15:04:17.503927   11641 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	35.691s
I0807 15:03:53.071238   11572 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0807 15:03:53.071556   11572 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0807 15:03:53.071667   11572 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0807 15:03:53.071708   11572 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
... skipping 53 lines ...
==================================
Random Seed: 1659884620
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: 1659884620
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0807 15:03:54.791910   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:04:03.115002   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:04:12.101056   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:04:23.231404   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:04:39.704704   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:04:52.713327   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:05:10.360797   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:05:31.284217   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:06:02.300814   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0807 15:06:47.458058   11572 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
E0807 15:06:47.468006   11572 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0807 15:06:47.468046   11572 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-784362841/tls.crt: no such file or directory"  
E0807 15:06:47.468066   11572 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0807 15:06:47.468085   11572 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-784362841/tls.crt: no such file or directory"  
I0807 15:06:47.468251   11572 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	186.616s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0807 15:04:05.820713   11917 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0807 15:04:05.820854   11917 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0807 15:04:05.921228   11917 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0807 15:04:06.024064   11917 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0807 15:04:06.024145   11917 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0807 15:04:06.131677   11917 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-4tanai"} 
E0807 15:04:06.162949   11917 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"
•I0807 15:04:07.217014   11917 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-l5cezv"} 
E0807 15:04:07.250149   11917 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"
•E0807 15:04:18.360186   11917 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.104 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
E0807 15:04:19.549181   11917 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"
•E0807 15:04:20.579192   11917 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"
•I0807 15:04:21.595946   11917 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0807 15:04:21.596020   11917 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0807 15:04:21.596124   11917 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0807 15:04:21.596239   11917 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 15:04:21.596300   11917 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-655554637/tls.crt: no such file or directory"  
E0807 15:04:21.598287   11917 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Patch http://127.0.0.1:44117/apis/addons.cluster.x-k8s.io/v1alpha3/namespaces/default/clusterresourcesets/test-clusterresourceset/status: read tcp 127.0.0.1:40622-\u003e127.0.0.1:44117: read: connection reset by peer" "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 29.624 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (29.62s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	29.733s
?   	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
E0807 15:03:57.165154   12093 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 92 lines ...
•I0807 15:04:08.581972   12093 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0807 15:04:08.624590   12093 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0807 15:04:08.628529   12093 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0807 15:04:08.657639   12093 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0807 15:04:08.715489   12093 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0807 15:04:08.718576   12093 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0807 15:04:08.718996   12093 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 15:04:08.719061   12093 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-873707006/tls.crt: no such file or directory"  
I0807 15:04:08.729248   12093 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


Ran 9 of 9 Specs in 11.523 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.52s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.821s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 201 lines ...
I0807 15:04:35.288751   15139 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0807 15:04:35.288941   15139 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0807 15:04:35.290018   15139 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0807 15:04:35.290300   15139 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39973
I0807 15:04:35.290400   15139 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I0807 15:04:36.168563   15139 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0807 15:04:36.168696   15139 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 15:04:36.168774   15139 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-131787609/tls.crt: no such file or directory"  


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