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

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0619 02:46:03.954870    8450 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0619 02:46:04.776957    8450 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" 
•I0619 02:46:04.800092    8450 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.427 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.43s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	44.857s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.03s)
=== 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.01s)
=== 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 ...
I0619 02:45:51.918438   10479 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0619 02:45:51.918475   10479 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":{}}}
I0619 02:45:51.918543   10479 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}}}
I0619 02:45:51.918576   10479 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0619 02:45:51.918616   10479 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0619 02:45:51.918952   10479 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2022/06/19 02:45:52 http: TLS handshake error from 127.0.0.1:35780: 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
I0619 02:45:52.217134   10479 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"
I0619 02:45:52.221199   10479 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
I0619 02:45:52.264453   10479 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
I0619 02:45:52.266002   10479 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"
E0619 02:45:52.266292   10479 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
I0619 02:45:52.266667   10479 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0619 02:45:52.637821   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0619 02:45:52.738478   10479 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0619 02:45:52.747355   10479 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-8kttn" "namespace"="test-machine-watches-xjpmb" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0619 02:45:52.747461   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0619 02:45:52.856118   10479 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-8kttn" "namespace"="test-machine-watches-xjpmb" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0619 02:45:52.856204   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0619 02:45:52.956705   10479 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-8kttn" "namespace"="test-machine-watches-xjpmb" "noderef"="node-1"
E0619 02:45:52.966733   10479 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0619 02:45:52.966796   10479 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0619 02:45:52.994085   10479 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-8kttn" "namespace"="test-machine-watches-xjpmb" "noderef"="node-1"
E0619 02:45:53.011573   10479 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-8kttn\" in namespace \"test-machine-watches-xjpmb\", requeuing: requeue in 1s"  
E0619 02:45:53.041115   10479 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-8kttn\" in namespace \"test-machine-watches-xjpmb\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-8kttn\" in namespace \"test-machine-watches-xjpmb\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-8kttn" "namespace"="test-machine-watches-xjpmb"
--- PASS: TestWatches (0.81s)
=== 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
I0619 02:45:53.280439   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-vgrl7" "namespace"="test-machine-watches-xjpmb" "count"=1
I0619 02:45:53.280502   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-vgrl7" "namespace"="test-machine-watches-xjpmb" "descendants"="Worker machines: machine-created-8kttn" "indirect descendants count"=0
I0619 02:45:53.294040   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-vgrl7" "namespace"="test-machine-watches-xjpmb" "count"=1
I0619 02:45:53.294163   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-vgrl7" "namespace"="test-machine-watches-xjpmb" "descendants"="Worker machines: machine-created-8kttn" "indirect descendants count"=0
I0619 02:45:54.041677   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-vgrl7" "machine"="machine-created-8kttn" "namespace"="test-machine-watches-xjpmb" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"7b27cd1f-b1c2-4fbe-9a56-61bbee879dcc","apiVersion":"v1"}
E0619 02:45:54.120817   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-8kttn\" not found" "controller"="machine" "name"="machine-created-8kttn" "namespace"="test-machine-watches-xjpmb"
E0619 02:45:55.164897   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-d5prl\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-gm578\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-gm578: secrets \"machine-reconcile-gm578-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-d5prl" "namespace"="default"
I0619 02:45:56.165450   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-gm578" "machine"="machine-created-d5prl" "namespace"="default" "cause"="noderef is nil" "node"=null
I0619 02:45:56.211404   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-gm578" "machine"="machine-created-d5prl" "namespace"="default" "cause"="noderef is nil" "node"=null
I0619 02:45:56.234212   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-gm578" "machine"="machine-created-d5prl" "namespace"="default" "cause"="noderef is nil" "node"=null
E0619 02:45:56.265124   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-d5prl\" not found" "controller"="machine" "name"="machine-created-d5prl" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.20s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.20s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.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
I0619 02:45:56.289156   10479 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0619 02:45:56.300848   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-gm578\" not found" "controller"="cluster" "name"="machine-reconcile-gm578" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0619 02:45:56.303185   10479 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0619 02:45:56.307033   10479 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.03s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.02s)
... skipping 111 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0619 02:45:56.432819   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6cq9" "namespace"="test-mhc-ztf4j" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0619 02:45:56.453454   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-kk4cm\" not found"  "cluster"="test-mhc-ztf4j/test-cluster-kk4cm"
I0619 02:45:56.453651   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0619 02:45:56.561397   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-h6cq9\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-h6cq9\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-h6cq9" "namespace"="test-mhc-ztf4j"
=== 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
I0619 02:45:57.561698   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6cq9" "namespace"="test-mhc-ztf4j" 
I0619 02:45:57.561815   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-k72g6" "namespace"="test-mhc-78lmm" 
I0619 02:45:57.561853   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7pxtv" "namespace"="test-mhc-psxkr" 
I0619 02:45:57.561887   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sxwgn" "namespace"="test-mhc-74wtn" 
I0619 02:45:57.595905   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:45:57.714279   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sxwgn" "namespace"="test-mhc-74wtn" 
I0619 02:45:57.714983   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sxwgn" "namespace"="test-mhc-74wtn" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0619 02:45:57.753497   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sxwgn" "namespace"="test-mhc-74wtn" 
E0619 02:45:57.768868   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-74wtn/test-cluster-qzx2x"
E0619 02:45:57.770624   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-qzx2x\" not found" "controller"="cluster" "name"="test-cluster-qzx2x" "namespace"="test-mhc-74wtn"
I0619 02:45:57.777320   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-752f6" "namespace"="test-mhc-wtfb8" 
I0619 02:45:57.791801   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:45:57.819413   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-752f6" "namespace"="test-mhc-wtfb8" 
E0619 02:45:57.882990   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wtfb8/test-cluster-sggqd"
I0619 02:45:57.886726   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-752f6" "namespace"="test-mhc-wtfb8" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0619 02:45:58.004897   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
inframachine created: test-mhc-machine-infra-56vx8
machine created: test-mhc-machine-9mtwb
I0619 02:45:58.050858   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:45:58.051261   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
I0619 02:45:58.091746   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.092157   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
I0619 02:45:58.100042   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.100427   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
I0619 02:45:58.101605   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.101892   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
I0619 02:45:58.114766   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.115323   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
node created: test-mhc-node-p724g
E0619 02:45:58.150237   10479 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-p724g"
E0619 02:45:58.150250   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p724g, got []"  "node"="test-mhc-node-p724g"
I0619 02:45:58.164961   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.165304   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
I0619 02:45:58.173293   10479 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-9mtwb" "namespace"="test-mhc-7dn55" "noderef"="test-mhc-node-p724g"
E0619 02:45:58.186629   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p724g, got []"  "node"="test-mhc-node-p724g"
E0619 02:45:58.186686   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p724g, got []"  "node"="test-mhc-node-p724g"
E0619 02:45:58.188309   10479 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-p724g"
E0619 02:45:58.188361   10479 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-p724g"
I0619 02:45:58.208076   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
inframachine created: test-mhc-machine-infra-74zff
machine created: test-mhc-machine-wrptn
I0619 02:45:58.256827   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.282002   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.291131   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
... skipping 51 lines ...
I0619 02:45:58.425226   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.427864   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.428962   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.429958   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.432046   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.433358   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.433659   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-wrptn/"
E0619 02:45:58.451636   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jc9j5, got []"  "node"="test-mhc-node-jc9j5"
E0619 02:45:58.451948   10479 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-jc9j5"
node created: test-mhc-node-jc9j5
I0619 02:45:58.452611   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.453222   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-wrptn/"
I0619 02:45:58.465865   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.466363   10479 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-7dn55/test-mhc-fgqnq/test-mhc-machine-wrptn/"
I0619 02:45:58.469199   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.488333   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
Cleaning up nodes, machines and infra machines.
I0619 02:45:58.492952   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.493456   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
I0619 02:45:58.511233   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:58.511994   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7dn55/test-mhc-fgqnq/test-mhc-machine-9mtwb/"
I0619 02:45:58.512662   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7dn55/test-mhc-fgqnq/test-mhc-machine-wrptn/"
I0619 02:45:58.533069   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hdx8h" "machine"="test-mhc-machine-9mtwb" "namespace"="test-mhc-7dn55" "cause"="no control plane members" "node"={"kind":"Node","name":"test-mhc-node-p724g","uid":"0a9b0a6a-3908-459e-b8b5-49d959ef3b98","apiVersion":"v1"}
E0619 02:45:58.537561   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7dn55/test-cluster-hdx8h"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-6mfht
E0619 02:45:58.593546   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9mtwb\" not found" "controller"="machine" "name"="test-mhc-machine-9mtwb" "namespace"="test-mhc-7dn55"
machine created: test-mhc-machine-gfk2f
E0619 02:45:58.657867   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-fgqnq\" not found" "controller"="machinehealthcheck" "name"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55"
E0619 02:45:58.787732   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-xjpmb/machine-reconcile-vgrl7"
E0619 02:45:59.593924   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:45:59.658218   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:45:59.682041   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:45:59.738376   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fgqnq" "namespace"="test-mhc-7dn55" 
I0619 02:45:59.738448   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:45:59.739841   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:45:59.741621   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
... skipping 398 lines ...
I0619 02:46:00.602741   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.604501   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.605349   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.607041   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.609029   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.609714   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.610023   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfk2f/"
E0619 02:46:00.610060   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:00.620204   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.620520   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfk2f/"
node created: test-mhc-node-xq4vj
E0619 02:46:00.710228   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xq4vj, got []"  "node"="test-mhc-node-xq4vj"
I0619 02:46:00.715617   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
inframachine created: test-mhc-machine-infra-lvrbl
I0619 02:46:00.756345   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
machine created: test-mhc-machine-672d6
I0619 02:46:00.763420   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:00.771476   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
... skipping 314 lines ...
I0619 02:46:01.655503   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.658133   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.659321   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.660485   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.661470   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.677848   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
E0619 02:46:01.678704   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:01.679382   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.682273   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.683807   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.685169   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.686970   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:01.690148   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
... skipping 362 lines ...
I0619 02:46:02.684556   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.686358   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.687411   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.689486   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.691674   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.693842   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.694182   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-672d6/"
I0619 02:46:02.712290   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.712741   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-672d6/"
I0619 02:46:02.714409   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.714806   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-672d6/"
E0619 02:46:02.714953   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
E0619 02:46:02.789584   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gdgkn, got []"  "node"="test-mhc-node-gdgkn"
node created: test-mhc-node-gdgkn
I0619 02:46:02.797859   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
inframachine created: test-mhc-machine-infra-szgng
machine created: test-mhc-machine-gfksv
I0619 02:46:02.816862   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:02.823312   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
... skipping 331 lines ...
I0619 02:46:03.826529   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.829735   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.831348   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.833893   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.848927   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.852268   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
E0619 02:46:03.856159   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:03.856427   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.859636   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.862514   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.865262   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.868018   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:03.870759   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
... skipping 289 lines ...
I0619 02:46:04.862038   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.871043   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.872754   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.874300   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.875722   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.877207   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.877659   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
I0619 02:46:04.898310   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.898845   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
E0619 02:46:04.902773   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:04.903061   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.903663   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
node created: test-mhc-node-xbcjq
E0619 02:46:04.931291   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xbcjq, got []"  "node"="test-mhc-node-xbcjq"
Cleaning up nodes, machines and infra machines.
I0619 02:46:04.941079   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.941617   10479 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-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/test-mhc-node-xbcjq"
I0619 02:46:04.966173   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.966719   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
Cleaning up nodes, machines and infra machines.
I0619 02:46:04.976849   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.977409   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
I0619 02:46:04.979878   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:04.980397   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfk2f/"
I0619 02:46:04.996975   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
I0619 02:46:05.003226   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:05.003847   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfk2f/"
I0619 02:46:05.004316   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-672d6/"
I0619 02:46:05.017166   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
I0619 02:46:05.021601   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-wzqzg" "namespace"="test-mhc-jd2qd" "count"=2
I0619 02:46:05.021683   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-wzqzg" "namespace"="test-mhc-jd2qd" "descendants"="Worker machines: test-mhc-machine-gfk2f,test-mhc-machine-672d6,test-mhc-machine-gfksv" "indirect descendants count"=1
I0619 02:46:05.026581   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-wzqzg" "namespace"="test-mhc-jd2qd" "count"=2
I0619 02:46:05.026643   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-wzqzg" "namespace"="test-mhc-jd2qd" "descendants"="Worker machines: test-mhc-machine-gfksv,test-mhc-machine-gfk2f,test-mhc-machine-672d6" "indirect descendants count"=1
I0619 02:46:05.027686   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:05.028315   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfk2f/"
I0619 02:46:05.028735   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-672d6/"
I0619 02:46:05.029179   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jd2qd/test-mhc-7cjtw/test-mhc-machine-gfksv/"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
E0619 02:46:05.033175   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-7cjtw\" not found" "controller"="machinehealthcheck" "name"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd"
inframachine created: test-mhc-machine-infra-mbpww
machine created: test-mhc-machine-dksld
I0619 02:46:05.903275   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wzqzg" "machine"="test-mhc-machine-gfksv" "namespace"="test-mhc-jd2qd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xbcjq"}
E0619 02:46:05.957562   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gfksv\" not found" "controller"="machine" "name"="test-mhc-machine-gfksv" "namespace"="test-mhc-jd2qd"
I0619 02:46:06.033440   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7cjtw" "namespace"="test-mhc-jd2qd" 
I0619 02:46:06.033553   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.049638   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:46:06.080316   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.086403   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.096538   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.137458   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.218569   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.379619   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.700776   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:06.958113   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wzqzg" "machine"="test-mhc-machine-672d6" "namespace"="test-mhc-jd2qd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gdgkn"}
E0619 02:46:07.008332   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-672d6\" not found" "controller"="machine" "name"="test-mhc-machine-672d6" "namespace"="test-mhc-jd2qd"
I0619 02:46:07.341921   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:08.008903   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wzqzg" "machine"="test-mhc-machine-gfk2f" "namespace"="test-mhc-jd2qd" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xq4vj"}
E0619 02:46:08.061947   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gfk2f\" not found" "controller"="machine" "name"="test-mhc-machine-gfk2f" "namespace"="test-mhc-jd2qd"
I0619 02:46:08.623069   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
E0619 02:46:09.080118   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:09.080362   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
E0619 02:46:09.091573   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-shbqz, got []"  "node"="test-mhc-node-shbqz"
node created: test-mhc-node-shbqz
E0619 02:46:09.091819   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-shbqz, got []"  "node"="test-mhc-node-shbqz"
inframachine created: test-mhc-machine-infra-j5b8x
I0619 02:46:09.117827   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
machine created: test-mhc-machine-q6vbh
I0619 02:46:09.133778   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:09.145604   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:09.150773   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:09.171983   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:09.213219   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:09.294563   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:09.455978   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:09.777416   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
E0619 02:46:10.039153   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jd2qd/test-cluster-wzqzg"
I0619 02:46:10.100934   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:10.109452   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:10.132378   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:10.139650   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:10.164083   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
E0619 02:46:10.173118   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:10.175272   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:10.200780   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
node created: test-mhc-node-6ct5v
E0619 02:46:10.241533   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6ct5v, got []"  "node"="test-mhc-node-6ct5v"
I0619 02:46:10.252574   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
inframachine created: test-mhc-machine-infra-f6trz
I0619 02:46:10.265783   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
machine created: test-mhc-machine-f8r8m
I0619 02:46:10.290141   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:10.418804   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.191038   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.209166   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.216099   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.232963   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.242676   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.253173   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
E0619 02:46:11.257262   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:11.257634   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
E0619 02:46:11.285258   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q55b8, got []"  "node"="test-mhc-node-q55b8"
node created: test-mhc-node-q55b8
I0619 02:46:11.344874   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
Cleaning up nodes, machines and infra machines.
I0619 02:46:11.371958   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.397340   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
Cleaning up nodes, machines and infra machines.
I0619 02:46:11.431384   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:11.438579   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7ft2w" "namespace"="test-mhc-wgn8v" "count"=2
I0619 02:46:11.438673   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7ft2w" "namespace"="test-mhc-wgn8v" "descendants"="Worker machines: test-mhc-machine-dksld,test-mhc-machine-q6vbh,test-mhc-machine-f8r8m" "indirect descendants count"=1
I0619 02:46:11.444165   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7ft2w" "namespace"="test-mhc-wgn8v" "count"=2
I0619 02:46:11.444231   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7ft2w" "namespace"="test-mhc-wgn8v" "descendants"="Worker machines: test-mhc-machine-dksld,test-mhc-machine-q6vbh,test-mhc-machine-f8r8m" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
E0619 02:46:11.472982   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6cgns\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v"
inframachine created: test-mhc-machine-infra-qdqmf
machine created: test-mhc-machine-5cb2z
I0619 02:46:12.257820   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7ft2w" "machine"="test-mhc-machine-dksld" "namespace"="test-mhc-wgn8v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-shbqz"}
E0619 02:46:12.326325   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dksld\" not found" "controller"="machine" "name"="test-mhc-machine-dksld" "namespace"="test-mhc-wgn8v"
I0619 02:46:12.473303   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6cgns" "namespace"="test-mhc-wgn8v" 
I0619 02:46:12.473423   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:12.508394   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:46:12.636305   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:13.326898   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7ft2w" "machine"="test-mhc-machine-q6vbh" "namespace"="test-mhc-wgn8v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-6ct5v"}
E0619 02:46:13.364115   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-q6vbh\" not found" "controller"="machine" "name"="test-mhc-machine-q6vbh" "namespace"="test-mhc-wgn8v"
I0619 02:46:14.364655   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7ft2w" "machine"="test-mhc-machine-f8r8m" "namespace"="test-mhc-wgn8v" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-q55b8"}
E0619 02:46:14.427066   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f8r8m\" not found" "controller"="machine" "name"="test-mhc-machine-f8r8m" "namespace"="test-mhc-wgn8v"
I0619 02:46:15.436871   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
E0619 02:46:15.441589   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:15.442187   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
node created: test-mhc-node-2rnzv
E0619 02:46:15.525812   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2rnzv, got []"  "node"="test-mhc-node-2rnzv"
E0619 02:46:15.525812   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2rnzv, got []"  "node"="test-mhc-node-2rnzv"
I0619 02:46:15.533638   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
inframachine created: test-mhc-machine-infra-57l48
machine created: test-mhc-machine-pc6b8
I0619 02:46:15.550243   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:15.565352   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.458449   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
E0619 02:46:16.458637   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wgn8v/test-cluster-7ft2w"
I0619 02:46:16.459425   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.469534   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.483430   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.488706   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.512842   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.520967   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.533956   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.548268   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
E0619 02:46:16.557899   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zl9fc, got []"  "node"="test-mhc-node-zl9fc"
node created: test-mhc-node-zl9fc
I0619 02:46:16.562503   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.568834   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
inframachine created: test-mhc-machine-infra-h9s8z
machine created: test-mhc-machine-tq2d7
I0619 02:46:16.617929   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
... skipping 6 lines ...
Cleaning up nodes, machines and infra machines.
I0619 02:46:16.719830   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.724136   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
Cleaning up nodes, machines and infra machines.
I0619 02:46:16.738043   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.744839   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.745434   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lclxx/test-mhc-fdlwh/test-mhc-machine-5cb2z/"
I0619 02:46:16.777239   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:16.777841   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lclxx/test-mhc-fdlwh/test-mhc-machine-5cb2z/"
I0619 02:46:16.778262   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lclxx/test-mhc-fdlwh/test-mhc-machine-pc6b8/"
I0619 02:46:16.804218   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2hg6v" "namespace"="test-mhc-lclxx" "count"=3
I0619 02:46:16.804305   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2hg6v" "namespace"="test-mhc-lclxx" "descendants"="Worker machines: test-mhc-machine-tq2d7,test-mhc-machine-5cb2z,test-mhc-machine-pc6b8" "indirect descendants count"=0
I0619 02:46:16.809717   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2hg6v" "namespace"="test-mhc-lclxx" "count"=3
I0619 02:46:16.809781   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2hg6v" "namespace"="test-mhc-lclxx" "descendants"="Worker machines: test-mhc-machine-5cb2z,test-mhc-machine-pc6b8,test-mhc-machine-tq2d7" "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
E0619 02:46:16.912086   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-fdlwh\" not found" "controller"="machinehealthcheck" "name"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx"
inframachine created: test-mhc-machine-infra-r78pb
machine created: test-mhc-machine-tsppb
E0619 02:46:16.956598   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-pc6b8\" in namespace \"test-mhc-lclxx\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-pc6b8" "namespace"="test-mhc-lclxx"
I0619 02:46:17.912361   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fdlwh" "namespace"="test-mhc-lclxx" 
I0619 02:46:17.912467   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:17.927218   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:46:17.945605   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:17.946728   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:17.948546   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
... skipping 24 lines ...
I0619 02:46:18.007996   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.010147   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.011953   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.013996   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.016463   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.018384   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
E0619 02:46:18.018904   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-tq2d7\" not found" "controller"="machine" "name"="test-mhc-machine-tq2d7" "namespace"="test-mhc-lclxx"
I0619 02:46:18.020472   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.022291   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.024139   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.025885   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.027649   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:18.029804   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
... skipping 461 lines ...
I0619 02:46:19.046134   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.055485   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.057537   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.059367   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.064750   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.069689   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
E0619 02:46:19.071100   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5cb2z\" not found" "controller"="machine" "name"="test-mhc-machine-5cb2z" "namespace"="test-mhc-lclxx"
I0619 02:46:19.076416   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.079345   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.081660   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.085114   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.088140   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:19.090063   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
... skipping 453 lines ...
I0619 02:46:20.087202   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.087820   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.088926   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.090614   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.092316   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2hg6v" "machine"="test-mhc-machine-pc6b8" "namespace"="test-mhc-lclxx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zl9fc"}
I0619 02:46:20.092586   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.092836   10479 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-t7lx7/test-mhc-2cwgl/test-mhc-machine-tsppb/"
I0619 02:46:20.108027   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.108326   10479 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-t7lx7/test-mhc-2cwgl/test-mhc-machine-tsppb/"
E0619 02:46:20.137969   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-pc6b8\" not found" "controller"="machine" "name"="test-mhc-machine-pc6b8" "namespace"="test-mhc-lclxx"
E0619 02:46:20.170197   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hz9hx, got []"  "node"="test-mhc-node-hz9hx"
E0619 02:46:20.170883   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hz9hx, got []"  "node"="test-mhc-node-hz9hx"
node created: test-mhc-node-hz9hx
I0619 02:46:20.194495   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.208235   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.213632   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.217911   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.218951   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.219194   10479 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-t7lx7/test-mhc-2cwgl/test-mhc-machine-tsppb/test-mhc-node-hz9hx"
I0619 02:46:20.238198   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.238617   10479 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-t7lx7/test-mhc-2cwgl/test-mhc-machine-tsppb/test-mhc-node-hz9hx"
Cleaning up nodes, machines and infra machines.
I0619 02:46:20.251874   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.252202   10479 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-t7lx7/test-mhc-2cwgl/test-mhc-machine-tsppb/"
I0619 02:46:20.266521   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2xbct" "namespace"="test-mhc-t7lx7" "descendants"="Worker machines: test-mhc-machine-tsppb" "indirect descendants count"=1
I0619 02:46:20.271228   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2xbct" "namespace"="test-mhc-t7lx7" "descendants"="Worker machines: test-mhc-machine-tsppb" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0619 02:46:20.398246   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2cwgl" "namespace"="test-mhc-t7lx7" 
I0619 02:46:20.404068   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" "creating"=1 "need"=1
I0619 02:46:20.404117   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
I0619 02:46:20.415351   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-895zc-qf2gn\"" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
I0619 02:46:20.501531   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:20.528506   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:46:20.551697   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:20.552515   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
E0619 02:46:21.138435   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:21.551895   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
E0619 02:46:21.833502   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lclxx/test-cluster-2hg6v"
I0619 02:46:22.139066   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2xbct" "machine"="test-mhc-machine-tsppb" "namespace"="test-mhc-t7lx7" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hz9hx"}
E0619 02:46:22.187885   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-tsppb\" not found" "controller"="machine" "name"="test-mhc-machine-tsppb" "namespace"="test-mhc-t7lx7"
I0619 02:46:22.552965   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:23.197477   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:23.197554   10479 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
I0619 02:46:23.205717   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:23.206515   10479 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
I0619 02:46:23.217700   10479 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
... skipping 7 lines ...
I0619 02:46:23.255887   10479 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:23.255948   10479 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:23.554051   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:24.242478   10479 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:24.242546   10479 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.000725   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.001221   10479 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-gk4gl/test-mhc-ggh4w/mhc-ms-895zc-qf2gn/"
I0619 02:46:25.009590   10479 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.015589   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.016035   10479 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-gk4gl/test-mhc-ggh4w/mhc-ms-895zc-qf2gn/"
I0619 02:46:25.017631   10479 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.017671   10479 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.025275   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.025672   10479 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-gk4gl/test-mhc-ggh4w/mhc-ms-895zc-qf2gn/"
I0619 02:46:25.026627   10479 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.044855   10479 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.044909   10479 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.067442   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rhd4k" "namespace"="test-mhc-gk4gl" "count"=1
I0619 02:46:25.068196   10479 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-rhd4k" "namespace"="test-mhc-gk4gl" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-895zc"
I0619 02:46:25.068983   10479 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" "machine"="mhc-ms-895zc-qf2gn"
I0619 02:46:25.074658   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggh4w" "namespace"="test-mhc-gk4gl" 
I0619 02:46:25.074949   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rhd4k" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" "cause"="cluster is being deleted" "node"=null
I0619 02:46:25.084802   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rhd4k" "namespace"="test-mhc-gk4gl" "descendants"="Machine sets: mhc-ms-895zc;Worker machines: mhc-ms-895zc-qf2gn" "indirect descendants count"=1
I0619 02:46:25.087304   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" "creating"=1 "need"=1
I0619 02:46:25.087350   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
E0619 02:46:25.090964   10479 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to sync machines: failed to clone infrastructure configuration for MachineSet \"mhc-ms-895zc\" in namespace \"test-mhc-gk4gl\": failed to retrieve InfrastructureMachineTemplate external object \"test-mhc-gk4gl\"/\"mhc-ms-template-7fx74\": infrastructuremachinetemplates.infrastructure.cluster.x-k8s.io \"mhc-ms-template-7fx74\" not found. failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-895zc\" not found" "machineset"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl" 
E0619 02:46:25.091036   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to sync machines: failed to clone infrastructure configuration for MachineSet \"mhc-ms-895zc\" in namespace \"test-mhc-gk4gl\": failed to retrieve InfrastructureMachineTemplate external object \"test-mhc-gk4gl\"/\"mhc-ms-template-7fx74\": infrastructuremachinetemplates.infrastructure.cluster.x-k8s.io \"mhc-ms-template-7fx74\" not found. failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-895zc\" not found" "controller"="machineset" "name"="mhc-ms-895zc" "namespace"="test-mhc-gk4gl"
I0619 02:46:25.091458   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rhd4k" "namespace"="test-mhc-gk4gl" "descendants"="Worker machines: mhc-ms-895zc-qf2gn" "indirect descendants count"=1
I0619 02:46:25.261475   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rhd4k" "machine"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl" "cause"="cluster is being deleted" "node"=null
E0619 02:46:25.309768   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-t7lx7/test-cluster-2xbct"
E0619 02:46:25.310593   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-895zc-qf2gn\" not found" "controller"="machine" "name"="mhc-ms-895zc-qf2gn" "namespace"="test-mhc-gk4gl"
I0619 02:46:25.329446   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
inframachine created: test-mhc-machine-infra-9x26s
machine created: test-mhc-machine-xp5xx
I0619 02:46:25.346214   10479 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 02:46:25.473571   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:25.474601   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
... skipping 348 lines ...
I0619 02:46:26.314563   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.316616   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.319349   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.320135   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.321252   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.323567   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
E0619 02:46:26.324064   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
I0619 02:46:26.324372   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
E0619 02:46:26.354668   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t4gdx, got []"  "node"="test-mhc-node-t4gdx"
node created: test-mhc-node-t4gdx
E0619 02:46:26.354966   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t4gdx, got []"  "node"="test-mhc-node-t4gdx"
I0619 02:46:26.397818   10479 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-xp5xx" "target"="test-mhc-85kpk/test-mhc-9b42q/test-mhc-machine-xp5xx/"
I0619 02:46:26.413020   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.435569   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.438049   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.443547   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.446873   10479 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-xp5xx" "target"="test-mhc-85kpk/test-mhc-9b42q/test-mhc-machine-xp5xx/test-mhc-node-t4gdx"
I0619 02:46:26.463860   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
Cleaning up nodes, machines and infra machines.
I0619 02:46:26.479334   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.483493   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.487558   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9b42q" "namespace"="test-mhc-85kpk" 
I0619 02:46:26.495215   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mxnjq" "namespace"="test-mhc-85kpk" "descendants"="Worker machines: test-mhc-machine-xp5xx" "indirect descendants count"=1
... skipping 357 lines ...
I0619 02:46:27.375201   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.376922   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.378643   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.380397   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.382335   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.384182   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
E0619 02:46:27.384224   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xp5xx\" not found" "controller"="machine" "name"="test-mhc-machine-xp5xx" "namespace"="test-mhc-85kpk"
I0619 02:46:27.386011   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.387812   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.389611   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.391365   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.393105   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:27.394887   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
... skipping 466 lines ...
I0619 02:46:28.387403   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.389129   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.391000   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.391838   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.394079   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.396490   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.401924   10479 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-mgmnw" "target"="test-mhc-sct7x/test-mhc-m6k4q/test-mhc-machine-mgmnw/"
I0619 02:46:28.421613   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
E0619 02:46:28.461477   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m4m2x, got []"  "node"="test-mhc-node-m4m2x"
node created: test-mhc-node-m4m2x
E0619 02:46:28.462224   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m4m2x, got []"  "node"="test-mhc-node-m4m2x"
E0619 02:46:28.462385   10479 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m4m2x, got []"  "node"="test-mhc-node-m4m2x"
I0619 02:46:28.469138   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.491923   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.502820   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.508084   10479 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-mgmnw" "target"="test-mhc-sct7x/test-mhc-m6k4q/test-mhc-machine-mgmnw/test-mhc-node-m4m2x"
I0619 02:46:28.534878   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.548071   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.568782   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
Cleaning up nodes, machines and infra machines.
I0619 02:46:28.590072   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.594274   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
I0619 02:46:28.603661   10479 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-mgmnw" "target"="test-mhc-sct7x/test-mhc-m6k4q/test-mhc-machine-mgmnw/"
I0619 02:46:28.611744   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hhqt9" "namespace"="test-mhc-sct7x" "descendants"="Worker machines: test-mhc-machine-mgmnw" "indirect descendants count"=1
I0619 02:46:28.616934   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hhqt9" "namespace"="test-mhc-sct7x" "descendants"="Worker machines: test-mhc-machine-mgmnw" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (32.21s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.14s)
... skipping 12 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.42s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.11s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0619 02:46:28.622978   10479 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
E0619 02:46:28.624976   10479 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
E0619 02:46:28.626862   10479 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0619 02:46:28.627119   10479 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
E0619 02:46:28.627678   10479 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
E0619 02:46:28.631276   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-m6k4q\" not found" "controller"="machinehealthcheck" "name"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x"
--- PASS: TestNodeToMachineHealthCheck (0.01s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_two_Machines_exist_for_the_Node (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace (0.00s)
... skipping 27 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
I0619 02:46:28.632717   10479 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0619 02:46:28.633376   10479 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0619 02:46:28.635175   10479 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
E0619 02:46:28.646810   10479 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
E0619 02:46:28.648593   10479 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 58 lines ...
Running Suite: Controllers Suite
================================
Random Seed: 1655606740
Will run 16 of 16 specs

•I0619 02:46:28.768799   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hhqt9" "machine"="test-mhc-machine-mgmnw" "namespace"="test-mhc-sct7x" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-m4m2x"}
E0619 02:46:28.785991   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-6hsgs\" not found" "controller"="cluster" "name"="test1-6hsgs" "namespace"="default"
E0619 02:46:29.016185   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mgmnw\" not found" "controller"="machine" "name"="test-mhc-machine-mgmnw" "namespace"="test-mhc-sct7x"
I0619 02:46:29.631540   10479 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m6k4q" "namespace"="test-mhc-sct7x" 
•I0619 02:46:29.922163   10479 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-7fbjb" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0619 02:46:30.046871   10479 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-7fbjb" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0619 02:46:30.051978   10479 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-7fbjb" "namespace"="default"
E0619 02:46:31.072993   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
•E0619 02:46:32.115818   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gk4gl/test-cluster-rhd4k"
E0619 02:46:32.145628   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-jwbxq\" not found" "controller"="cluster" "name"="test3-jwbxq" "namespace"="default"
E0619 02:46:33.146387   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
E0619 02:46:34.164689   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
E0619 02:46:34.165095   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-85kpk/test-cluster-mxnjq"
•E0619 02:46:35.177072   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-sct7x/test-cluster-hhqt9"
E0619 02:46:35.181114   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pv9rd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pv9rd" "namespace"="default"
E0619 02:46:36.181845   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
E0619 02:46:36.564395   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-hdx8h\" for machine \"test-mhc-machine-wrptn\" in namespace \"test-mhc-7dn55\": Cluster.cluster.x-k8s.io \"test-cluster-hdx8h\" not found" "controller"="machine" "name"="test-mhc-machine-wrptn" "namespace"="test-mhc-7dn55"
E0619 02:46:37.191568   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pv9rd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pv9rd" "namespace"="default"
•E0619 02:46:38.192372   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
E0619 02:46:39.193150   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pv9rd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pv9rd" "namespace"="default"
E0619 02:46:40.203058   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
I0619 02:46:40.341032   10479 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-gw2c7" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0619 02:46:40.357393   10479 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-gw2c7" "namespace"="default" 
E0619 02:46:40.376277   10479 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-gw2c7" "namespace"="default"
E0619 02:46:41.203938   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pv9rd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pv9rd" "namespace"="default"
I0619 02:46:41.398434   10479 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-gw2c7" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0619 02:46:41.398688   10479 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-gw2c7" "namespace"="default" "noderef"="id-node-1"
E0619 02:46:41.414404   10479 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-gw2c7" "namespace"="default"
E0619 02:46:42.208831   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
•I0619 02:46:42.217970   10479 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"
I0619 02:46:42.218767   10479 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0619 02:46:42.218808   10479 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"
I0619 02:46:42.219408   10479 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0619 02:46:42.219437   10479 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0619 02:46:42.219915   10479 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
... skipping 13 lines ...
I0619 02:46:42.230772   10479 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"
•I0619 02:46:42.232166   10479 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"
I0619 02:46:42.232798   10479 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"
I0619 02:46:42.233381   10479 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0619 02:46:42.233413   10479 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0619 02:46:42.233897   10479 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0619 02:46:42.235101   10479 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" 
•I0619 02:46:42.278613   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0619 02:46:42.278650   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.288386   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-w6b2x-6657c7fddb-nqb7n\"" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.288527   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.302351   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-w6b2x-6657c7fddb-v5r8x\"" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.374968   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0619 02:46:42.375008   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.383150   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-w6b2x-6657c7fddb-59txh\"" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.383249   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.391953   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-w6b2x-6657c7fddb-kc8qf\"" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.414926   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-lcx96" "machine"="test6-gw2c7" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"d9a1be7a-8477-495e-87c4-adba9b120ff4","apiVersion":"v1"}
E0619 02:46:42.432060   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-gw2c7\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-gw2c7" "namespace"="default"
I0619 02:46:42.486625   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0619 02:46:42.486678   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.495716   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w6b2x-6657c7fddb-79dkx\"" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" 
I0619 02:46:42.592514   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0619 02:46:42.592552   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" 
I0619 02:46:42.602363   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w6b2x-cdfc6fd6c-sz2lj\"" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" 
E0619 02:46:42.811632   10479 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-w6b2x-cdfc6fd6c-sz2lj-hvsbk for machine md-test/md-w6b2x-cdfc6fd6c-sz2lj: the cache is not started, can not read objects" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" 
I0619 02:46:42.837712   10479 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0619 02:46:42.837748   10479 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0619 02:46:42.844490   10479 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "machine"="md-w6b2x-6657c7fddb-59txh"
I0619 02:46:42.861199   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0619 02:46:42.861240   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" 
I0619 02:46:42.872301   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w6b2x-cdfc6fd6c-cl44n\"" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" 
... skipping 3 lines ...
I0619 02:46:43.118269   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0619 02:46:43.118307   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" 
I0619 02:46:43.127496   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w6b2x-cdfc6fd6c-7vwt7\"" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" 
I0619 02:46:43.198600   10479 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0619 02:46:43.198637   10479 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0619 02:46:43.205618   10479 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w6b2x-6657c7fddb" "namespace"="md-test" "machine"="md-w6b2x-6657c7fddb-79dkx"
E0619 02:46:43.209404   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-pv9rd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-pv9rd" "namespace"="default"
I0619 02:46:43.458051   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-lcx96" "machine"="test6-gw2c7" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"d9a1be7a-8477-495e-87c4-adba9b120ff4","apiVersion":"v1"}
E0619 02:46:43.458776   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-gw2c7\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-gw2c7" "namespace"="default"
I0619 02:46:43.463471   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0619 02:46:43.463590   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-w6b2x-74d45c49c5" "namespace"="md-test" 
I0619 02:46:43.473729   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w6b2x-74d45c49c5-rrp9n\"" "machineset"="md-w6b2x-74d45c49c5" "namespace"="md-test" 
I0619 02:46:43.696732   10479 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0619 02:46:43.696766   10479 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0619 02:46:43.700591   10479 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "machine"="md-w6b2x-cdfc6fd6c-cl44n"
... skipping 5 lines ...
I0619 02:46:43.932005   10479 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "machine"="md-w6b2x-cdfc6fd6c-7vwt7"
I0619 02:46:44.040998   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w6b2x-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0619 02:46:44.041034   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-w6b2x-74d45c49c5" "namespace"="md-test" 
I0619 02:46:44.051204   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w6b2x-74d45c49c5-2vjfp\"" "machineset"="md-w6b2x-74d45c49c5" "namespace"="md-test" 
I0619 02:46:44.209977   10479 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-lcx96" "namespace"="default" "count"=1
I0619 02:46:44.210051   10479 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-lcx96" "namespace"="default" "descendants"="Control plane machines: test6-gw2c7" "indirect descendants count"=0
E0619 02:46:44.224433   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-7fbjb: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-7fbjb" "namespace"="default"
E0619 02:46:44.286180   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-w6b2x\" not found" "controller"="machinedeployment" "name"="md-w6b2x" "namespace"="md-test"
I0619 02:46:44.286317   10479 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0619 02:46:44.286355   10479 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
•I0619 02:46:44.290753   10479 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w6b2x-cdfc6fd6c" "namespace"="md-test" "machine"="md-w6b2x-cdfc6fd6c-sz2lj"
I0619 02:46:44.417607   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-klkrd" "namespace"="ms-test" "creating"=2 "need"=2
I0619 02:46:44.417642   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-klkrd" "namespace"="ms-test" 
I0619 02:46:44.430536   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-klkrd-rdb5p\"" "machineset"="ms-klkrd" "namespace"="ms-test" 
I0619 02:46:44.430583   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-klkrd" "namespace"="ms-test" 
I0619 02:46:44.442321   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-klkrd-n544t\"" "machineset"="ms-klkrd" "namespace"="ms-test" 
I0619 02:46:44.465037   10479 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-w6b2x-6657c7fddb-nqb7n" "namespace"="md-test" 
I0619 02:46:44.465075   10479 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-w6b2x-6657c7fddb-nqb7n" "namespace"="md-test" 
I0619 02:46:44.479529   10479 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-w6b2x-6657c7fddb-v5r8x" "namespace"="md-test" 
I0619 02:46:44.479565   10479 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-w6b2x-6657c7fddb-v5r8x" "namespace"="md-test" 
I0619 02:46:44.501190   10479 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-lcx96" "machine"="test6-gw2c7" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"d9a1be7a-8477-495e-87c4-adba9b120ff4","apiVersion":"v1"}
E0619 02:46:44.501966   10479 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-gw2c7\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-gw2c7" "namespace"="default"
I0619 02:46:44.578202   10479 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-klkrd" "namespace"="ms-test" "creating"=1 "need"=2
I0619 02:46:44.578248   10479 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-klkrd" "namespace"="ms-test" 
I0619 02:46:44.595942   10479 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-klkrd-nrwtm\"" "machineset"="ms-klkrd" "namespace"="ms-test" 
E0619 02:46:44.720503   10479 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-klkrd-nrwtm-sql7q for machine ms-test/ms-klkrd-nrwtm: the cache is not started, can not read objects" "machineset"="ms-klkrd" "namespace"="ms-test" 
E0619 02:46:44.946601   10479 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•

Ran 16 of 16 Specs in 16.299 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.30s)
PASS
Tearing down test suite
I0619 02:46:44.949584   10479 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0619 02:46:44.949628   10479 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0619 02:46:44.949592   10479 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0619 02:46:44.949650   10479 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0619 02:46:44.949657   10479 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0619 02:46:44.949660   10479 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0619 02:46:44.949664   10479 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0619 02:46:44.986568   10479 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:36337/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1273&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:36337: connect: connection refused
E0619 02:46:44.986623   10479 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:36337/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1273&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:36337: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	64.676s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0619 02:45:54.063630   10863 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"
I0619 02:45:54.063645   10863 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0619 02:45:54.063852   10863 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0619 02:45:54.064736   10863 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0619 02:45:54.064901   10863 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=35781
I0619 02:45:54.064970   10863 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0619 02:45:56.304122   10863 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-qrw4j/test-cluster"
•E0619 02:45:56.765297   10863 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-wk6pl/test-cluster"
•E0619 02:45:57.307853   10863 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:36839/?timeout=50ms: dial tcp 127.0.0.1:36839: connect: connection refused"  "cluster"="cluster-cache-test-dqm25/test-cluster"
•I0619 02:45:57.532784   10863 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":{}}}
I0619 02:45:57.733363   10863 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0619 02:45:57.733447   10863 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0619 02:45:57.733721   10863 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0619 02:45:58.265218   10863 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0619 02:45:58.281538   10863 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}}}
I0619 02:45:58.383035   10863 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0619 02:45:58.383104   10863 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0619 02:45:58.568094   10863 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0619 02:45:58.568226   10863 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0619 02:45:58.636992   10863 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:39161/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:39161: connect: connection refused


Ran 5 of 5 Specs in 16.379 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.38s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.632s
?   	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
I0619 02:46:06.642869   11559 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
E0619 02:46:06.644139   11559 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
I0619 02:46:06.644717   11559 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0619 02:46:06.644851   11559 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0619 02:46:21.869805   11559 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
I0619 02:46:21.869922   11559 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: 1655606753
Will run 1 of 1 specs

E0619 02:46:21.903176   11559 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-5to6u2\" not found" "kubeadmControlPlane"="kcp-foo-5to6u2" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.030 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.03s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0619 02:46:21.904324   11559 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-s3affd" "kubeadmControlPlane"="kcp-foo-s3affd" "namespace"="test" 
I0619 02:46:23.568983   11559 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-s3affd" "kubeadmControlPlane"="kcp-foo-s3affd" "namespace"="test" "needRollout"=["kcp-foo-s3affd-blxts"]
I0619 02:46:23.569267   11559 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-s3affd" "kubeadmControlPlane"="kcp-foo-s3affd" "namespace"="test" "failures"="[machine kcp-foo-s3affd-v8hhk does not have APIServerPodHealthy condition, machine kcp-foo-s3affd-v8hhk does not have ControllerManagerPodHealthy condition, machine kcp-foo-s3affd-v8hhk does not have SchedulerPodHealthy condition, machine kcp-foo-s3affd-v8hhk does not have EtcdPodHealthy condition, machine kcp-foo-s3affd-v8hhk does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.67s)
... skipping 60 lines ...
==================================
Random Seed: 1655606752
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: 1655606752
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0619 02:46:07.219779   11519 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"  
E0619 02:46:15.543060   11519 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"  
E0619 02:46:24.529072   11519 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"  
E0619 02:46:35.659450   11519 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"  
E0619 02:46:52.132661   11519 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"  
E0619 02:47:05.141203   11519 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"  
E0619 02:47:22.788657   11519 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"  
E0619 02:47:43.712017   11519 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"  
E0619 02:48:14.728531   11519 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"  
E0619 02:48:59.885687   11519 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
E0619 02:48:59.894409   11519 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0619 02:48:59.894489   11519 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0619 02:48:59.894638   11519 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-101473715/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	187.922s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
... skipping 287 lines ...
I0619 02:46:14.759519   11885 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0619 02:46:14.763501   11885 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0619 02:46:14.863961   11885 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0619 02:46:14.964400   11885 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0619 02:46:14.964474   11885 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0619 02:46:15.049049   11885 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-op102r"} 
E0619 02:46:15.088457   11885 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"
•I0619 02:46:16.123188   11885 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-z9b9qw"} 
E0619 02:46:16.163137   11885 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"
•E0619 02:46:17.236497   11885 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0619 02:46:18.259709   11885 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"
•E0619 02:46:19.462678   11885 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"
E0619 02:46:20.503091   11885 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"
•E0619 02:46:21.518765   11885 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"
•I0619 02:46:21.522175   11885 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0619 02:46:21.522266   11885 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0619 02:46:21.522286   11885 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0619 02:46:21.522322   11885 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-376741312/tls.crt: no such file or directory"  
I0619 02:46:21.522440   11885 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 5 of 5 Specs in 19.685 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (19.69s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	19.777s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0619 02:46:07.027584   12102 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 92 lines ...
•I0619 02:46:18.338500   12102 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0619 02:46:18.368470   12102 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0619 02:46:18.388008   12102 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0619 02:46:18.403041   12102 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}}}
I0619 02:46:18.420474   12102 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0619 02:46:18.443640   12102 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0619 02:46:18.446522   12102 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0619 02:46:18.446575   12102 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-116006940/tls.crt: no such file or directory"  
E0619 02:46:18.446590   12102 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0619 02:46:18.446607   12102 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-116006940/tls.crt: no such file or directory"  
I0619 02:46:18.446777   12102 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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

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



Summarizing 1 Failure:

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

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