This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-06-25 02:45
Elapsed4m19s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0625 02:47:00.104111    8281 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0625 02:47:00.697984    8281 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" 
•I0625 02:47:00.707057    8281 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.396 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.40s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	43.549s
=== 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 ...
I0625 02:46:47.650844   10422 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0625 02:46:47.650875   10422 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0625 02:46:47.650915   10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0625 02:46:47.651197   10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
I0625 02:46:47.651658   10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0625 02:46:47.651728   10422 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2022/06/25 02:46:48 http: TLS handshake error from 127.0.0.1:56272: 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
I0625 02:46:48.055666   10422 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"
I0625 02:46:48.060473   10422 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
I0625 02:46:48.084854   10422 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
I0625 02:46:48.094609   10422 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"
E0625 02:46:48.095053   10422 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
I0625 02:46:48.095547   10422 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.01s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.01s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0625 02:46:48.379631   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0625 02:46:48.382176   10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0625 02:46:48.386529   10422 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0625 02:46:48.386606   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0625 02:46:48.495260   10422 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0625 02:46:48.495336   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0625 02:46:48.595830   10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "noderef"="node-1"
E0625 02:46:48.619464   10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0625 02:46:48.619507   10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0625 02:46:48.643384   10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "noderef"="node-1"
E0625 02:46:48.664012   10422 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-wb6rc\" in namespace \"test-machine-watches-pf5l7\", requeuing: requeue in 1s"  
E0625 02:46:48.674494   10422 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-wb6rc\" in namespace \"test-machine-watches-pf5l7\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-wb6rc\" in namespace \"test-machine-watches-pf5l7\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7"
--- PASS: TestWatches (0.60s)
=== 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
I0625 02:46:48.892906   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "count"=1
I0625 02:46:48.892965   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "descendants"="Worker machines: machine-created-wb6rc" "indirect descendants count"=0
I0625 02:46:48.905492   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "count"=1
I0625 02:46:48.905551   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-vvq2s" "namespace"="test-machine-watches-pf5l7" "descendants"="Worker machines: machine-created-wb6rc" "indirect descendants count"=0
I0625 02:46:49.674944   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-vvq2s" "machine"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"b139bddf-92ae-4411-9d90-0249261c1a82","apiVersion":"v1"}
E0625 02:46:49.725761   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-wb6rc\" not found" "controller"="machine" "name"="machine-created-wb6rc" "namespace"="test-machine-watches-pf5l7"
E0625 02:46:50.770099   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-7mrc5\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-lbskn\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-lbskn: secrets \"machine-reconcile-lbskn-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-7mrc5" "namespace"="default"
I0625 02:46:51.770724   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lbskn" "machine"="machine-created-7mrc5" "namespace"="default" "cause"="noderef is nil" "node"=null
I0625 02:46:51.803807   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lbskn" "machine"="machine-created-7mrc5" "namespace"="default" "cause"="noderef is nil" "node"=null
I0625 02:46:51.952086   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-lbskn" "machine"="machine-created-7mrc5" "namespace"="default" "cause"="noderef is nil" "node"=null
E0625 02:46:51.979591   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-7mrc5\" not found" "controller"="machine" "name"="machine-created-7mrc5" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.30s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.30s)
=== 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 6 lines ...
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0625 02:46:52.001802   10422 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"
I0625 02:46:52.001966   10422 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
I0625 02:46:52.004569   10422 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"
I0625 02:46:52.004794   10422 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
E0625 02:46:52.012566   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-lbskn\" not found" "controller"="cluster" "name"="machine-reconcile-lbskn" "namespace"="default"
--- PASS: TestMachineOwnerReference (0.02s)
    --- 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.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
... skipping 118 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/scaling_up (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0625 02:46:52.186582   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-84lht" "namespace"="test-mhc-x2dc2" 
I0625 02:46:52.211962   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0625 02:46:52.212893   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-x9cvl\" not found"  "cluster"="test-mhc-x2dc2/test-cluster-x9cvl"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0625 02:46:52.216218   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-84lht\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-84lht\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-84lht" "namespace"="test-mhc-x2dc2"
=== 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
I0625 02:46:53.217786   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-84lht" "namespace"="test-mhc-x2dc2" 
I0625 02:46:53.217939   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwszn" "namespace"="test-mhc-xwn2h" 
I0625 02:46:53.217979   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zxs5q" "namespace"="test-mhc-fcfxw" 
I0625 02:46:53.218013   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cj6kd" "namespace"="test-mhc-rj9v4" 
I0625 02:46:53.239120   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0625 02:46:53.271827   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cj6kd" "namespace"="test-mhc-rj9v4" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0625 02:46:53.328442   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cj6kd" "namespace"="test-mhc-rj9v4" 
E0625 02:46:53.342450   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rj9v4/test-cluster-nx55r"
E0625 02:46:53.345930   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-nx55r\" not found" "controller"="cluster" "name"="test-cluster-nx55r" "namespace"="test-mhc-rj9v4"
I0625 02:46:53.456098   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svq6k" "namespace"="test-mhc-wzwtv" 
I0625 02:46:53.472052   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0625 02:46:53.491251   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svq6k" "namespace"="test-mhc-wzwtv" 
E0625 02:46:53.573751   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wzwtv/test-cluster-7bxrb"
I0625 02:46:53.579574   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svq6k" "namespace"="test-mhc-wzwtv" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0625 02:46:53.608516   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
inframachine created: test-mhc-machine-infra-mnjnz
I0625 02:46:53.620017   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-5hplm
I0625 02:46:53.656362   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.660622   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.661428   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.661611   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.668802   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.669032   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.678504   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.678800   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.687537   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.687810   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.693342   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.693609   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.704203   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.704470   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.712406   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.712670   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
node created: test-mhc-node-8chs6
E0625 02:46:53.744621   10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-8chs6"
E0625 02:46:53.744858   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8chs6, got []"  "node"="test-mhc-node-8chs6"
I0625 02:46:53.752589   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
inframachine created: test-mhc-machine-infra-xxvzb
machine created: test-mhc-machine-7twhq
I0625 02:46:53.771311   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.789729   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.790114   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
I0625 02:46:53.805183   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.805550   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
I0625 02:46:53.819199   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.820511   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
I0625 02:46:53.838844   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.839276   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
I0625 02:46:53.845381   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.845944   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
E0625 02:46:53.868485   10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-knfw9"
E0625 02:46:53.868485   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-knfw9, got []"  "node"="test-mhc-node-knfw9"
I0625 02:46:53.868893   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
node created: test-mhc-node-knfw9
I0625 02:46:53.869274   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
I0625 02:46:53.873106   10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2" "noderef"="test-mhc-node-knfw9"
E0625 02:46:53.876669   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-knfw9, got []"  "node"="test-mhc-node-knfw9"
E0625 02:46:53.876721   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-knfw9, got []"  "node"="test-mhc-node-knfw9"
E0625 02:46:53.876923   10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-knfw9"
E0625 02:46:53.876961   10422 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-knfw9"
I0625 02:46:53.883486   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.883876   10422 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-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
I0625 02:46:53.889940   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.906522   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
Cleaning up nodes, machines and infra machines.
I0625 02:46:53.916409   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.916843   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.935437   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:53.935859   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vq5f2/test-mhc-vcjgs/test-mhc-machine-5hplm/"
I0625 02:46:53.936277   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vq5f2/test-mhc-vcjgs/test-mhc-machine-7twhq/"
E0625 02:46:53.961527   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vq5f2/test-cluster-zrd25"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-vz66j
machine created: test-mhc-machine-dcx7x
E0625 02:46:54.094321   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-vcjgs\" not found" "controller"="machinehealthcheck" "name"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2"
E0625 02:46:54.142949   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
E0625 02:46:54.358637   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-pf5l7/machine-reconcile-vvq2s"
I0625 02:46:55.094623   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:55.131285   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0625 02:46:55.144609   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:46:55.157492   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vcjgs" "namespace"="test-mhc-vq5f2" 
I0625 02:46:55.157672   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:55.158524   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:55.165358   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:55.168687   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:55.174015   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
... skipping 444 lines ...
I0625 02:46:56.152928   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.154740   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.156550   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.157655   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.158714   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.160491   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
E0625 02:46:56.161977   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:46:56.162154   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.162691   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.162976   10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-dcx7x/"
I0625 02:46:56.173549   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:56.173781   10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-dcx7x/"
E0625 02:46:56.215574   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hkdgc, got []"  "node"="test-mhc-node-hkdgc"
node created: test-mhc-node-hkdgc
I0625 02:46:56.221906   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
inframachine created: test-mhc-machine-infra-wtfft
I0625 02:46:56.236044   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
machine created: test-mhc-machine-zhl5z
I0625 02:46:56.249191   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
... skipping 358 lines ...
I0625 02:46:57.150816   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.152739   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.154604   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.156455   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.158355   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.160417   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
E0625 02:46:57.162248   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:46:57.162348   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.164166   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.166027   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.167889   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.169820   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:57.171961   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
... skipping 405 lines ...
I0625 02:46:58.188174   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.190388   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.192599   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.193655   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.195837   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.198117   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
E0625 02:46:58.198793   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:46:58.199686   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.200781   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.201855   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.211050   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.212579   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:58.213630   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
... skipping 385 lines ...
I0625 02:46:59.198274   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.200582   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.204214   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.207106   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.208131   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.210172   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.210657   10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-zhl5z/"
E0625 02:46:59.211632   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:46:59.230158   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.231586   10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-zhl5z/"
E0625 02:46:59.261807   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jgzrp, got []"  "node"="test-mhc-node-jgzrp"
node created: test-mhc-node-jgzrp
I0625 02:46:59.268967   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
inframachine created: test-mhc-machine-infra-7ll7w
machine created: test-mhc-machine-5wmg6
I0625 02:46:59.287179   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:46:59.291982   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
... skipping 301 lines ...
I0625 02:47:00.209724   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.212379   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.214723   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.221696   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.224454   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.226304   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
E0625 02:47:00.226502   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:00.227517   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.228789   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.230003   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.231701   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.233401   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:00.235029   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
... skipping 324 lines ...
I0625 02:47:01.272431   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.273757   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.275171   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.276479   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.277782   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.283845   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
E0625 02:47:01.284158   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:47:01.292890   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.294543   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.298393   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.303617   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.306942   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:01.309496   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
... skipping 287 lines ...
I0625 02:47:02.280542   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.289374   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.293243   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.295642   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.298331   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.307153   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.307574   10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/"
E0625 02:47:02.308243   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8s7g9, got []"  "node"="test-mhc-node-8s7g9"
node created: test-mhc-node-8s7g9
E0625 02:47:02.311121   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:02.319269   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.319851   10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/"
I0625 02:47:02.328561   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.329043   10422 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-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/test-mhc-node-8s7g9"
Cleaning up nodes, machines and infra machines.
Cleaning up nodes, machines and infra machines.
I0625 02:47:02.349029   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.349498   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/"
I0625 02:47:02.373964   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:02.374485   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jgrsc/test-mhc-64wp4/test-mhc-machine-dcx7x/"
I0625 02:47:02.391845   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jgrsc/test-mhc-64wp4/test-mhc-machine-5wmg6/"
I0625 02:47:02.410348   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "count"=2
I0625 02:47:02.410430   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "descendants"="Worker machines: test-mhc-machine-dcx7x,test-mhc-machine-zhl5z,test-mhc-machine-5wmg6" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
E0625 02:47:02.420487   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-64wp4\" not found" "controller"="machinehealthcheck" "name"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc"
I0625 02:47:02.435208   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "count"=2
I0625 02:47:02.435304   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-22vp6" "namespace"="test-mhc-jgrsc" "descendants"="Worker machines: test-mhc-machine-dcx7x,test-mhc-machine-zhl5z,test-mhc-machine-5wmg6" "indirect descendants count"=1
inframachine created: test-mhc-machine-infra-h6cdp
machine created: test-mhc-machine-njglz
I0625 02:47:03.311699   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-22vp6" "machine"="test-mhc-machine-zhl5z" "namespace"="test-mhc-jgrsc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jgzrp"}
E0625 02:47:03.351310   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zhl5z\" not found" "controller"="machine" "name"="test-mhc-machine-zhl5z" "namespace"="test-mhc-jgrsc"
I0625 02:47:03.420724   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-64wp4" "namespace"="test-mhc-jgrsc" 
I0625 02:47:03.420867   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:03.439446   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0625 02:47:03.556424   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:03.561553   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:03.582257   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:03.623104   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:03.704104   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:03.865027   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:04.185932   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:04.351666   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:47:04.826944   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:05.352173   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-22vp6" "machine"="test-mhc-machine-5wmg6" "namespace"="test-mhc-jgrsc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8s7g9"}
E0625 02:47:05.390590   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5wmg6\" not found" "controller"="machine" "name"="test-mhc-machine-5wmg6" "namespace"="test-mhc-jgrsc"
I0625 02:47:06.107980   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:06.391184   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-22vp6" "machine"="test-mhc-machine-dcx7x" "namespace"="test-mhc-jgrsc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hkdgc"}
E0625 02:47:06.450224   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dcx7x\" not found" "controller"="machine" "name"="test-mhc-machine-dcx7x" "namespace"="test-mhc-jgrsc"
E0625 02:47:07.437203   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jgrsc/test-cluster-22vp6"
E0625 02:47:07.450559   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:08.458400   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:08.461624   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:47:08.462401   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:08.481887   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:08.486188   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vx6kq, got []"  "node"="test-mhc-node-vx6kq"
node created: test-mhc-node-vx6kq
I0625 02:47:08.492368   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
inframachine created: test-mhc-machine-infra-5pm8p
machine created: test-mhc-machine-plhqm
I0625 02:47:08.528206   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:08.540275   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:08.549917   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:08.560034   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:08.601519   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:08.683820   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:08.845104   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:09.166504   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:09.462121   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:09.807766   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.475427   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.480535   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.490280   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.498516   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.513016   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.518848   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:10.520042   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
node created: test-mhc-node-4q9kd
I0625 02:47:10.541346   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:10.543358   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4q9kd, got []"  "node"="test-mhc-node-4q9kd"
I0625 02:47:10.546758   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
inframachine created: test-mhc-machine-infra-twvxb
machine created: test-mhc-machine-6ctb2
I0625 02:47:10.560272   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.561895   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.572181   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:10.577393   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:11.089070   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:11.520449   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:12.534003   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:12.550589   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:12.558644   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:12.574989   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:12.580776   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:12.586914   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:12.591880   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:12.594947   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:47:12.607493   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
E0625 02:47:12.680915   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pnwld, got []"  "node"="test-mhc-node-pnwld"
node created: test-mhc-node-pnwld
I0625 02:47:12.689871   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
Cleaning up nodes, machines and infra machines.
I0625 02:47:12.699521   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
Cleaning up nodes, machines and infra machines.
I0625 02:47:12.732739   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8j4q9" "namespace"="test-mhc-n4s2v" "count"=2
... skipping 4 lines ...
I0625 02:47:12.842006   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dv7hg" "namespace"="test-mhc-n4s2v" 
I0625 02:47:12.861965   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
inframachine created: test-mhc-machine-infra-2tvnq
machine created: test-mhc-machine-jnlv5
I0625 02:47:12.885825   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0625 02:47:12.904346   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
E0625 02:47:13.595352   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:14.595793   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8j4q9" "machine"="test-mhc-machine-njglz" "namespace"="test-mhc-n4s2v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vx6kq"}
E0625 02:47:14.633764   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-njglz\" not found" "controller"="machine" "name"="test-mhc-machine-njglz" "namespace"="test-mhc-n4s2v"
I0625 02:47:15.634355   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8j4q9" "machine"="test-mhc-machine-plhqm" "namespace"="test-mhc-n4s2v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4q9kd"}
E0625 02:47:15.694884   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-plhqm\" not found" "controller"="machine" "name"="test-mhc-machine-plhqm" "namespace"="test-mhc-n4s2v"
I0625 02:47:16.695389   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8j4q9" "machine"="test-mhc-machine-6ctb2" "namespace"="test-mhc-n4s2v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pnwld"}
E0625 02:47:16.726701   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6ctb2\" not found" "controller"="machine" "name"="test-mhc-machine-6ctb2" "namespace"="test-mhc-n4s2v"
I0625 02:47:17.733713   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
E0625 02:47:17.742917   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:47:17.743250   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
E0625 02:47:17.756292   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-n4s2v/test-cluster-8j4q9"
node created: test-mhc-node-vqqkw
E0625 02:47:17.809582   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vqqkw, got []"  "node"="test-mhc-node-vqqkw"
I0625 02:47:17.816198   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
inframachine created: test-mhc-machine-infra-8tsf7
machine created: test-mhc-machine-g5t8l
I0625 02:47:17.842308   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:17.848876   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
E0625 02:47:18.743260   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:19.764696   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:19.770109   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:19.787945   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:19.797525   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:19.803980   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:19.808195   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
E0625 02:47:19.808523   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
node created: test-mhc-node-jxfm8
E0625 02:47:19.851314   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jxfm8, got []"  "node"="test-mhc-node-jxfm8"
I0625 02:47:19.856937   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
inframachine created: test-mhc-machine-infra-jvxqs
I0625 02:47:19.879248   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
machine created: test-mhc-machine-9qrzw
I0625 02:47:19.888558   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:19.894474   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
... skipping 8 lines ...
I0625 02:47:20.889719   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
Cleaning up nodes, machines and infra machines.
I0625 02:47:20.895159   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
Cleaning up nodes, machines and infra machines.
I0625 02:47:20.906616   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:20.908038   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:20.908475   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-jnlv5/"
I0625 02:47:20.942293   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:20.942859   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-jnlv5/"
I0625 02:47:20.943292   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-g5t8l/"
I0625 02:47:20.958593   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
I0625 02:47:20.959130   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-g5t8l/"
I0625 02:47:20.959581   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-gjjqb/test-mhc-vmgr6/test-mhc-machine-jnlv5/"
I0625 02:47:20.961476   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kt6q2" "namespace"="test-mhc-gjjqb" "count"=3
I0625 02:47:20.961551   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-kt6q2" "namespace"="test-mhc-gjjqb" "descendants"="Worker machines: test-mhc-machine-jnlv5,test-mhc-machine-g5t8l,test-mhc-machine-9qrzw" "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
I0625 02:47:20.965766   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmgr6" "namespace"="test-mhc-gjjqb" 
... skipping 54 lines ...
I0625 02:47:21.114448   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.122275   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.124829   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.126581   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.129045   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.130811   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
E0625 02:47:21.132300   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-g5t8l\" in namespace \"test-mhc-gjjqb\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-g5t8l" "namespace"="test-mhc-gjjqb"
I0625 02:47:21.132489   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.134628   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.136490   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.138216   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.139919   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:21.141662   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
... skipping 511 lines ...
I0625 02:47:22.170215   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.173370   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.175009   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.176655   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.178360   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.180031   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
E0625 02:47:22.180788   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9qrzw\" not found" "controller"="machine" "name"="test-mhc-machine-9qrzw" "namespace"="test-mhc-gjjqb"
I0625 02:47:22.181733   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.183340   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.184984   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.189380   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.191032   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:22.192737   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
... skipping 518 lines ...
I0625 02:47:23.220226   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.221918   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.223640   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.225366   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.227048   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.228758   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
E0625 02:47:23.229686   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jnlv5\" not found" "controller"="machine" "name"="test-mhc-machine-jnlv5" "namespace"="test-mhc-gjjqb"
I0625 02:47:23.230451   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.232211   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.233958   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.235721   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.237485   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:23.239233   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
... skipping 515 lines ...
I0625 02:47:24.235323   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.236963   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.239469   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.240287   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.241170   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.242517   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.242732   10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/"
I0625 02:47:24.242988   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kt6q2" "machine"="test-mhc-machine-g5t8l" "namespace"="test-mhc-gjjqb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jxfm8"}
I0625 02:47:24.251573   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.251836   10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/"
E0625 02:47:24.283274   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-g5t8l\" not found" "controller"="machine" "name"="test-mhc-machine-g5t8l" "namespace"="test-mhc-gjjqb"
E0625 02:47:24.343071   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fnwkn, got []"  "node"="test-mhc-node-fnwkn"
E0625 02:47:24.343324   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fnwkn, got []"  "node"="test-mhc-node-fnwkn"
node created: test-mhc-node-fnwkn
I0625 02:47:24.350382   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.364860   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.365922   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.375108   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.375465   10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn"
I0625 02:47:24.390345   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.390822   10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn"
Cleaning up nodes, machines and infra machines.
I0625 02:47:24.402477   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.402939   10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn"
I0625 02:47:24.404900   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.405203   10422 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-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/test-mhc-node-fnwkn"
I0625 02:47:24.407124   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.410596   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/"
I0625 02:47:24.423449   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qjkqt" "namespace"="test-mhc-48fwl" "descendants"="Worker machines: test-mhc-machine-frlqr" "indirect descendants count"=1
I0625 02:47:24.423659   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
I0625 02:47:24.423944   10422 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-48fwl/test-mhc-c66wq/test-mhc-machine-frlqr/"
I0625 02:47:24.427193   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c66wq" "namespace"="test-mhc-48fwl" 
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0625 02:47:24.427940   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qjkqt" "namespace"="test-mhc-48fwl" "descendants"="Worker machines: test-mhc-machine-frlqr" "indirect descendants count"=1
I0625 02:47:24.627337   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" "creating"=1 "need"=1
I0625 02:47:24.627384   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" 
I0625 02:47:24.648516   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-2h97j-t8lvk\"" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" 
I0625 02:47:24.696015   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:24.720973   10422 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0625 02:47:24.838036   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:24.846416   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
E0625 02:47:25.283666   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:25.838300   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
E0625 02:47:25.979068   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gjjqb/test-cluster-kt6q2"
E0625 02:47:26.284103   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:47:26.839391   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:27.284632   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qjkqt" "machine"="test-mhc-machine-frlqr" "namespace"="test-mhc-48fwl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-fnwkn"}
E0625 02:47:27.320281   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-frlqr\" not found" "controller"="machine" "name"="test-mhc-machine-frlqr" "namespace"="test-mhc-48fwl"
I0625 02:47:27.840315   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.327513   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.328045   10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.331448   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.331847   10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.337646   10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
... skipping 4 lines ...
I0625 02:47:28.347683   10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.351967   10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.352006   10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
I0625 02:47:28.841252   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:29.351812   10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
I0625 02:47:29.351859   10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
E0625 02:47:29.436383   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-48fwl/test-cluster-qjkqt"
I0625 02:47:30.000574   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.000933   10422 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-kjqr9/test-mhc-jclhx/mhc-ms-2h97j-t8lvk/"
I0625 02:47:30.006607   10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.009785   10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.009818   10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.011545   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.011897   10422 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-kjqr9/test-mhc-jclhx/mhc-ms-2h97j-t8lvk/"
I0625 02:47:30.016280   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.016344   10422 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.016570   10422 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-kjqr9/test-mhc-jclhx/mhc-ms-2h97j-t8lvk/"
I0625 02:47:30.021652   10422 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.021678   10422 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" 
I0625 02:47:30.037351   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-l9vnb" "namespace"="test-mhc-kjqr9" "count"=1
I0625 02:47:30.037412   10422 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-l9vnb" "namespace"="test-mhc-kjqr9" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-2h97j"
I0625 02:47:30.037862   10422 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-2h97j" "namespace"="test-mhc-kjqr9" "machine"="mhc-ms-2h97j-t8lvk"
I0625 02:47:30.040571   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jclhx" "namespace"="test-mhc-kjqr9" 
... skipping 16 lines ...
I0625 02:47:30.236122   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.237864   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.238581   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.240284   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.241179   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-l9vnb" "machine"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9" "cause"="cluster is being deleted" "node"=null
I0625 02:47:30.241576   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
E0625 02:47:30.265434   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-2h97j-t8lvk\" not found" "controller"="machine" "name"="mhc-ms-2h97j-t8lvk" "namespace"="test-mhc-kjqr9"
I0625 02:47:30.282934   10422 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-mb7wc" "target"="test-mhc-8n46k/test-mhc-2tqk4/test-mhc-machine-mb7wc/"
I0625 02:47:30.291851   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
node created: test-mhc-node-gr2ch
E0625 02:47:30.308646   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gr2ch, got []"  "node"="test-mhc-node-gr2ch"
E0625 02:47:30.308903   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gr2ch, got []"  "node"="test-mhc-node-gr2ch"
I0625 02:47:30.312967   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.325814   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.335346   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.337801   10422 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-mb7wc" "target"="test-mhc-8n46k/test-mhc-2tqk4/test-mhc-machine-mb7wc/test-mhc-node-gr2ch"
I0625 02:47:30.349999   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
Cleaning up nodes, machines and infra machines.
I0625 02:47:30.359476   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.361278   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.364481   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2tqk4" "namespace"="test-mhc-8n46k" 
I0625 02:47:30.367961   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mr826" "namespace"="test-mhc-8n46k" "descendants"="Worker machines: test-mhc-machine-mb7wc" "indirect descendants count"=1
... skipping 511 lines ...
I0625 02:47:31.285418   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.287089   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.290206   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.291802   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.293501   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.295020   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
E0625 02:47:31.296660   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mb7wc\" not found" "controller"="machine" "name"="test-mhc-machine-mb7wc" "namespace"="test-mhc-8n46k"
I0625 02:47:31.296721   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.298249   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.299848   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.301516   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.303388   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:31.305214   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
... skipping 585 lines ...
I0625 02:47:32.287938   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.289596   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.291336   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.292894   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.294428   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.295994   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
E0625 02:47:32.296975   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
I0625 02:47:32.297517   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.299201   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.300713   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.302279   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.303876   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:32.305475   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
... skipping 615 lines ...
I0625 02:47:33.303955   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.305112   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.305788   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.307379   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.309142   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.309964   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
E0625 02:47:33.310140   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
I0625 02:47:33.312912   10422 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-kc9h6" "target"="test-mhc-sds2d/test-mhc-kb7ll/test-mhc-machine-kc9h6/"
node created: test-mhc-node-nqrvp
E0625 02:47:33.319820   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nqrvp, got []"  "node"="test-mhc-node-nqrvp"
E0625 02:47:33.319852   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nqrvp, got []"  "node"="test-mhc-node-nqrvp"
E0625 02:47:33.319864   10422 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nqrvp, got []"  "node"="test-mhc-node-nqrvp"
I0625 02:47:33.322673   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.326445   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.344789   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.348799   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.352423   10422 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-kc9h6" "target"="test-mhc-sds2d/test-mhc-kb7ll/test-mhc-machine-kc9h6/test-mhc-node-nqrvp"
I0625 02:47:33.368147   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.371184   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.375308   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.395752   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
Cleaning up nodes, machines and infra machines.
I0625 02:47:33.410065   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
I0625 02:47:33.416399   10422 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-kc9h6" "target"="test-mhc-sds2d/test-mhc-kb7ll/test-mhc-machine-kc9h6/"
I0625 02:47:33.423541   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c25rk" "namespace"="test-mhc-sds2d" "descendants"="Worker machines: test-mhc-machine-kc9h6" "indirect descendants count"=1
I0625 02:47:33.433769   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-c25rk" "namespace"="test-mhc-sds2d" "descendants"="Worker machines: test-mhc-machine-kc9h6" "indirect descendants count"=1
E0625 02:47:33.434649   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-kb7ll\" not found" "controller"="machinehealthcheck" "name"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d"
--- PASS: TestMachineHealthCheck_Reconcile (41.28s)
    --- 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.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (0.96s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.25s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.33s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.06s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0625 02:47:33.437866   10422 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
E0625 02:47:33.439361   10422 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
E0625 02:47:33.440985   10422 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0625 02:47:33.441199   10422 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
E0625 02:47:33.441580   10422 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0625 02:47:33.444490   10422 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0625 02:47:33.444885   10422 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0625 02:47:33.445921   10422 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
E0625 02:47:33.457665   10422 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
E0625 02:47:33.460507   10422 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 ...
I0625 02:47:33.471959   10422 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"
•I0625 02:47:33.473760   10422 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"
I0625 02:47:33.474676   10422 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"
I0625 02:47:33.475576   10422 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0625 02:47:33.475641   10422 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0625 02:47:33.476238   10422 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0625 02:47:33.477792   10422 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" 
••E0625 02:47:33.600961   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-9jlqk\" not found" "controller"="cluster" "name"="test1-9jlqk" "namespace"="default"
I0625 02:47:34.310744   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c25rk" "machine"="test-mhc-machine-kc9h6" "namespace"="test-mhc-sds2d" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nqrvp"}
E0625 02:47:34.348521   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kc9h6\" not found" "controller"="machine" "name"="test-mhc-machine-kc9h6" "namespace"="test-mhc-sds2d"
I0625 02:47:34.434886   10422 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kb7ll" "namespace"="test-mhc-sds2d" 
•I0625 02:47:34.734050   10422 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-ndgsx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0625 02:47:34.856260   10422 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-ndgsx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0625 02:47:34.860567   10422 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-ndgsx" "namespace"="default"
E0625 02:47:35.872413   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
•E0625 02:47:36.882873   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kjqr9/test-cluster-l9vnb"
E0625 02:47:36.890942   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8n46k/test-cluster-mr826"
E0625 02:47:36.900690   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-rv48v\" not found" "controller"="cluster" "name"="test3-rv48v" "namespace"="default"
E0625 02:47:37.901337   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
E0625 02:47:38.911005   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
•E0625 02:47:39.920296   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-sds2d/test-cluster-c25rk"
E0625 02:47:39.923128   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bgb7h: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default"
E0625 02:47:40.923788   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
E0625 02:47:41.932612   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bgb7h: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default"
•E0625 02:47:42.537371   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-5hplm\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-5hplm" "namespace"="test-mhc-vq5f2"
E0625 02:47:42.933263   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
E0625 02:47:43.550434   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-zrd25\" for machine \"test-mhc-machine-7twhq\" in namespace \"test-mhc-vq5f2\": Cluster.cluster.x-k8s.io \"test-cluster-zrd25\" not found" "controller"="machine" "name"="test-mhc-machine-7twhq" "namespace"="test-mhc-vq5f2"
E0625 02:47:43.933872   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bgb7h: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default"
E0625 02:47:44.942116   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
I0625 02:47:45.012360   10422 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-m4js5" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0625 02:47:45.025037   10422 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-m4js5" "namespace"="default" 
E0625 02:47:45.037981   10422 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-m4js5" "namespace"="default"
E0625 02:47:45.942798   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bgb7h: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default"
I0625 02:47:46.051191   10422 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-m4js5" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0625 02:47:46.051383   10422 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-m4js5" "namespace"="default" "noderef"="id-node-1"
E0625 02:47:46.060896   10422 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-m4js5" "namespace"="default"
E0625 02:47:46.947434   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
•I0625 02:47:47.058043   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-gxcpw" "namespace"="ms-test" "creating"=2 "need"=2
I0625 02:47:47.058104   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-gxcpw" "namespace"="ms-test" 
I0625 02:47:47.061282   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-kgkfh" "machine"="test6-m4js5" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"b51521bb-bc99-4712-a725-6675a5ce9130","apiVersion":"v1"}
I0625 02:47:47.068564   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-gxcpw-dh68n\"" "machineset"="ms-gxcpw" "namespace"="ms-test" 
I0625 02:47:47.068666   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-gxcpw" "namespace"="ms-test" 
E0625 02:47:47.078816   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-m4js5\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-m4js5" "namespace"="default"
I0625 02:47:47.081068   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-gxcpw-s9gkk\"" "machineset"="ms-gxcpw" "namespace"="ms-test" 
I0625 02:47:47.180488   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-gxcpw" "namespace"="ms-test" "creating"=1 "need"=2
I0625 02:47:47.180527   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-gxcpw" "namespace"="ms-test" 
I0625 02:47:47.192289   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-gxcpw-fhh7p\"" "machineset"="ms-gxcpw" "namespace"="ms-test" 
E0625 02:47:47.417133   10422 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-gxcpw-fhh7p-r6gjj for machine ms-test/ms-gxcpw-fhh7p: the cache is not started, can not read objects" "machineset"="ms-gxcpw" "namespace"="ms-test" 
E0625 02:47:47.541189   10422 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0625 02:47:47.578610   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0625 02:47:47.578637   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" 
I0625 02:47:47.600679   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-b4v6b-6657c7fddb-pjzrw\"" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" 
I0625 02:47:47.600731   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" 
I0625 02:47:47.618010   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-b4v6b-6657c7fddb-x5p6h\"" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" 
I0625 02:47:47.670571   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
... skipping 4 lines ...
I0625 02:47:47.781049   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0625 02:47:47.781086   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" 
I0625 02:47:47.789065   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-6657c7fddb-9xlzg\"" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" 
I0625 02:47:47.895619   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0625 02:47:47.895652   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" 
I0625 02:47:47.908941   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-cdfc6fd6c-xkqd2\"" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" 
E0625 02:47:47.947907   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bgb7h: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bgb7h" "namespace"="default"
E0625 02:47:48.006800   10422 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-b4v6b-cdfc6fd6c-xkqd2-m9bf8 for machine md-test/md-b4v6b-cdfc6fd6c-xkqd2: the cache is not started, can not read objects" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" 
I0625 02:47:48.024773   10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0625 02:47:48.024808   10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0625 02:47:48.029873   10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "machine"="md-b4v6b-6657c7fddb-s4nwb"
I0625 02:47:48.047586   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0625 02:47:48.047642   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" 
I0625 02:47:48.056029   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-cdfc6fd6c-4d2x8\"" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" 
I0625 02:47:48.079275   10422 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-kgkfh" "machine"="test6-m4js5" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"b51521bb-bc99-4712-a725-6675a5ce9130","apiVersion":"v1"}
E0625 02:47:48.079792   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-m4js5\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-m4js5" "namespace"="default"
I0625 02:47:48.178956   10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0625 02:47:48.178988   10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0625 02:47:48.183469   10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-6657c7fddb" "namespace"="md-test" "machine"="md-b4v6b-6657c7fddb-5jqh6"
I0625 02:47:48.289668   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0625 02:47:48.289697   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" 
I0625 02:47:48.296783   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-cdfc6fd6c-m44wf\"" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" 
... skipping 5 lines ...
I0625 02:47:48.627944   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-74d45c49c5-r4nxf\"" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" 
I0625 02:47:48.936106   10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0625 02:47:48.936231   10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0625 02:47:48.939860   10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "machine"="md-b4v6b-cdfc6fd6c-4d2x8"
I0625 02:47:48.948273   10422 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-kgkfh" "namespace"="default" "count"=1
I0625 02:47:48.948337   10422 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-kgkfh" "namespace"="default" "descendants"="Control plane machines: test6-m4js5" "indirect descendants count"=0
E0625 02:47:48.962645   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-ndgsx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-ndgsx" "namespace"="default"
I0625 02:47:49.048614   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0625 02:47:49.048668   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" 
I0625 02:47:49.056788   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-74d45c49c5-zhqkd\"" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" 
E0625 02:47:49.080107   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-gxcpw-s9gkk\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-gxcpw-s9gkk" "namespace"="ms-test"
I0625 02:47:49.162018   10422 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0625 02:47:49.162053   10422 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0625 02:47:49.165238   10422 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-b4v6b-cdfc6fd6c" "namespace"="md-test" "machine"="md-b4v6b-cdfc6fd6c-m44wf"
I0625 02:47:49.271166   10422 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0625 02:47:49.271204   10422 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" 
I0625 02:47:49.277919   10422 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-b4v6b-74d45c49c5-2hbjk\"" "machineset"="md-b4v6b-74d45c49c5" "namespace"="md-test" 
E0625 02:47:49.499997   10422 machinedeployment_controller.go:149] controllers/MachineDeployment "msg"="Failed to reconcile MachineDeployment" "error"="MachineDeployment.cluster.x-k8s.io \"md-b4v6b\" not found" "machinedeployment"="md-b4v6b" "namespace"="md-test" 
E0625 02:47:49.500254   10422 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="MachineDeployment.cluster.x-k8s.io \"md-b4v6b\" not found" "controller"="machinedeployment" "name"="md-b4v6b" "namespace"="md-test"
•

Ran 16 of 16 Specs in 16.043 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.04s)
PASS
Tearing down test suite
E0625 02:47:49.505799   10422 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0625 02:47:49.505840   10422 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-887230872/tls.crt: no such file or directory"  
E0625 02:47:49.505860   10422 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0625 02:47:49.505880   10422 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-887230872/tls.crt: no such file or directory"  
I0625 02:47:49.505921   10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0625 02:47:49.505946   10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0625 02:47:49.506025   10422 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0625 02:47:49.506112   10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0625 02:47:49.506147   10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0625 02:47:49.506166   10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0625 02:47:49.506179   10422 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0625 02:47:49.531770   10422 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:34359/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1233&timeout=10s&timeoutSeconds=372&watch=true: dial tcp 127.0.0.1:34359: connect: connection refused
E0625 02:47:49.533261   10422 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:34359/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1233&timeout=10s&timeoutSeconds=393&watch=true: dial tcp 127.0.0.1:34359: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	73.229s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0625 02:46:48.953421   10837 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"
I0625 02:46:48.953442   10837 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0625 02:46:48.953593   10837 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0625 02:46:48.954415   10837 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0625 02:46:48.954602   10837 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=37379
I0625 02:46:48.954686   10837 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0625 02:46:51.210568   10837 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-bm82n/test-cluster"
•E0625 02:46:51.650989   10837 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-tp2s4/test-cluster"
•E0625 02:46:52.263363   10837 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:42831/?timeout=50ms: dial tcp 127.0.0.1:42831: connect: connection refused"  "cluster"="cluster-cache-test-zr4jg/test-cluster"
•I0625 02:46:52.499059   10837 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":{}}}
I0625 02:46:52.599362   10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0625 02:46:52.599416   10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0625 02:46:52.635914   10837 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0625 02:46:53.158627   10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0625 02:46:53.172562   10837 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}}}
I0625 02:46:53.272911   10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0625 02:46:53.272962   10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•E0625 02:46:53.456369   10837 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0625 02:46:53.456422   10837 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-978526235/tls.crt: no such file or directory"  
I0625 02:46:53.456512   10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0625 02:46:53.456574   10837 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0625 02:46:53.499448   10837 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:35901/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:35901: connect: connection refused


Ran 5 of 5 Specs in 15.364 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.36s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	15.558s
?   	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
I0625 02:46:59.575551   11539 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
E0625 02:46:59.576783   11539 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
I0625 02:46:59.577417   11539 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0625 02:46:59.577586   11539 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 94 lines ...
I0625 02:47:10.255240   11539 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-7lr6n" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-fglng (m2-healthy-fglng)","node-m3-healthy-8cgnp (m3-healthy-8cgnp)"] "targetQuorum"=2 "targetTotalMembers"=2 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0625 02:47:10.259702   11539 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-7lr6n"
=== RUN   TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade)
I0625 02:47:10.372305   11539 remediation.go:195]  "msg"="etcd cluster before remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "currentMembers"=["node-m1-unhealthy-r8bxm","node-m2-healthy-5pxcj","node-m3-healthy-5dnhf","node-m4-healthy-75glm"] "currentTotalMembers"=4
I0625 02:47:10.372380   11539 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-r8bxm" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-5pxcj (m2-healthy-5pxcj)","node-m3-healthy-5dnhf (m3-healthy-5dnhf)","node-m4-healthy-75glm (m4-healthy-75glm)"] "targetQuorum"=2 "targetTotalMembers"=3 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0625 02:47:10.375180   11539 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-r8bxm"
--- FAIL: TestReconcileUnhealthyMachines (0.65s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_are_no_unhealthy_machines (0.00s)
    --- PASS: TestReconcileUnhealthyMachines/reconcileUnhealthyMachines_return_early_if_the_machine_to_be_remediated_is_marked_for_deletion (0.00s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_desired_replicas_<=_1 (0.03s)
    --- FAIL: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_number_of_machines_lower_than_desired (0.03s)
        remediation_test.go:841: 
            Expected
                <string>: 
            to equal
                <string>: KCP waiting for having at least 3 control plane machines before triggering remediation
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_a_deleting_machine (0.04s)
... skipping 86 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
I0625 02:47:13.092980   11539 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
I0625 02:47:13.093149   11539 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: 1656125207
Will run 1 of 1 specs

E0625 02:47:13.119496   11539 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-mdx2uw\" not found" "kubeadmControlPlane"="kcp-foo-mdx2uw" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.022 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0625 02:47:13.121122   11539 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-q6uum1" "kubeadmControlPlane"="kcp-foo-q6uum1" "namespace"="test" 
I0625 02:47:14.814894   11539 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-q6uum1" "kubeadmControlPlane"="kcp-foo-q6uum1" "namespace"="test" "needRollout"=["kcp-foo-q6uum1-xctfl"]
I0625 02:47:14.815035   11539 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-q6uum1" "kubeadmControlPlane"="kcp-foo-q6uum1" "namespace"="test" "failures"="[machine kcp-foo-q6uum1-cshvx does not have APIServerPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have ControllerManagerPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have SchedulerPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have EtcdPodHealthy condition, machine kcp-foo-q6uum1-cshvx does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.70s)
FAIL
I0625 02:47:14.815757   11539 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	27.177s
I0625 02:46:57.996656   11502 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"
I0625 02:46:57.996761   11502 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0625 02:46:57.996792   11502 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"
I0625 02:46:57.996807   11502 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0625 02:46:57.996880   11502 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
I0625 02:46:57.996895   11502 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1656125207
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: 1656125207
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0625 02:46:59.884718   11502 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"  
E0625 02:47:08.209072   11502 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"  
E0625 02:47:17.195032   11502 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"  
E0625 02:47:28.325261   11502 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"  
E0625 02:47:44.798472   11502 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"  
E0625 02:47:57.807078   11502 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"  
E0625 02:48:15.454543   11502 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"  
E0625 02:48:36.377909   11502 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"  
E0625 02:49:07.394394   11502 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"  
E0625 02:49:52.551509   11502 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
E0625 02:49:52.557839   11502 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0625 02:49:52.557888   11502 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-428093671/tls.crt: no such file or directory"  
E0625 02:49:52.557904   11502 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0625 02:49:52.557922   11502 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-428093671/tls.crt: no such file or directory"  
I0625 02:49:52.558009   11502 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	185.241s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0625 02:47:07.869808   11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0625 02:47:07.870057   11862 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0625 02:47:07.970452   11862 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0625 02:47:08.070815   11862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0625 02:47:08.070889   11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0625 02:47:08.139657   11862 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-hnb1x7"} 
E0625 02:47:08.209587   11862 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"
•I0625 02:47:09.242138   11862 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-45tuc3"} 
E0625 02:47:09.269130   11862 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•
------------------------------
• Failure [11.079 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0625 02:47:20.362712   11862 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"
E0625 02:47:21.487400   11862 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"
•E0625 02:47:22.522616   11862 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"
E0625 02:47:23.535718   11862 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"
•I0625 02:47:23.536661   11862 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0625 02:47:23.536679   11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0625 02:47:23.536659   11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0625 02:47:23.536946   11862 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0625 02:47:23.537034   11862 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-959499860/tls.crt: no such file or directory"  



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 27.419 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (27.42s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	27.498s
?   	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
E0625 02:47:01.458505   12050 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
•I0625 02:47:12.367626   12050 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0625 02:47:12.369985   12050 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0625 02:47:12.404057   12050 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 10.881 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (10.88s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.132s
?   	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 204 lines ...
I0625 02:47:34.115121   15037 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0625 02:47:34.115164   15037 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=36193
••••••••••••••I0625 02:47:35.187539   15037 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 14 of 14 Specs in 7.756 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (7.76s)
=== 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.034s
FAIL
make: *** [Makefile:116: test] Error 1