This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-11-15 03:33
Elapsed4m27s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I1115 03:35:28.756789    8308 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I1115 03:35:28.756907    8308 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I1115 03:35:28.757769    8308 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I1115 03:35:28.757978    8308 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=46305
I1115 03:35:28.758143    8308 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I1115 03:35:29.629110    8308 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" 
•E1115 03:35:29.638516    8308 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1115 03:35:29.638560    8308 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-710672875/tls.crt: no such file or directory"  
E1115 03:35:29.638579    8308 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1115 03:35:29.638598    8308 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-710672875/tls.crt: no such file or directory"  
I1115 03:35:29.638955    8308 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.834 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.83s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	45.749s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I1115 03:35:17.244257   10495 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":{}}}
I1115 03:35:17.244351   10495 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":{}}}
I1115 03:35:17.244417   10495 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}}}
I1115 03:35:17.244463   10495 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I1115 03:35:17.244510   10495 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I1115 03:35:17.249393   10495 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2022/11/15 03:35:17 http: TLS handshake error from 127.0.0.1:33604: 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
I1115 03:35:17.543402   10495 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"
I1115 03:35:17.567772   10495 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
I1115 03:35:17.617253   10495 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
I1115 03:35:17.619920   10495 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"
E1115 03:35:17.620371   10495 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
I1115 03:35:17.621098   10495 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.01s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I1115 03:35:18.065888   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E1115 03:35:18.069354   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I1115 03:35:18.081369   10495 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I1115 03:35:18.081507   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I1115 03:35:18.195543   10495 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I1115 03:35:18.195681   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I1115 03:35:18.296476   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "noderef"="node-1"
E1115 03:35:18.321046   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E1115 03:35:18.321124   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E1115 03:35:18.383337   10495 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-5tcf5\" in namespace \"test-machine-watches-45dld\", requeuing: requeue in 1s"  
E1115 03:35:18.407204   10495 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-5tcf5\" in namespace \"test-machine-watches-45dld\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-5tcf5\" in namespace \"test-machine-watches-45dld\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld"
--- PASS: TestWatches (0.83s)
=== 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
I1115 03:35:18.538851   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "count"=1
I1115 03:35:18.538913   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "descendants"="Worker machines: machine-created-5tcf5" "indirect descendants count"=0
I1115 03:35:18.554138   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "count"=1
I1115 03:35:18.554199   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "descendants"="Worker machines: machine-created-5tcf5" "indirect descendants count"=0
I1115 03:35:19.407683   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-9r7v5" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"cef0e13e-1d7b-4bad-a2ca-ca2bdf449191","apiVersion":"v1"}
E1115 03:35:19.453322   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-5tcf5\" not found" "controller"="machine" "name"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld"
E1115 03:35:20.498866   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-qrfq6\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-cbxms\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-cbxms: secrets \"machine-reconcile-cbxms-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-qrfq6" "namespace"="default"
I1115 03:35:21.499451   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cbxms" "machine"="machine-created-qrfq6" "namespace"="default" "cause"="noderef is nil" "node"=null
I1115 03:35:21.560043   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cbxms" "machine"="machine-created-qrfq6" "namespace"="default" "cause"="noderef is nil" "node"=null
I1115 03:35:21.582954   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cbxms" "machine"="machine-created-qrfq6" "namespace"="default" "cause"="noderef is nil" "node"=null
E1115 03:35:21.619383   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-qrfq6\" not found" "controller"="machine" "name"="machine-created-qrfq6" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.18s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.18s)
=== 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 15 lines ...
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I1115 03:35:21.644809   10495 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"
=== RUN   TestReconcileRequest/machine_should_be_updated
I1115 03:35:21.649214   10495 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"
E1115 03:35:21.652334   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-cbxms\" not found" "controller"="cluster" "name"="machine-reconcile-cbxms" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I1115 03:35:21.654016   10495 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.02s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.00s)
    --- PASS: TestReconcileRequest/machine_should_be_updated (0.00s)
    --- PASS: TestReconcileRequest/machine_should_be_deleted (0.01s)
... skipping 109 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I1115 03:35:21.821278   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqfzq" "namespace"="test-mhc-r7qjm" 
I1115 03:35:21.835871   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E1115 03:35:21.836919   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-fvqzd\" not found"  "cluster"="test-mhc-r7qjm/test-cluster-fvqzd"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E1115 03:35:21.849307   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-xqfzq\" not found" "controller"="machinehealthcheck" "name"="test-mhc-xqfzq" "namespace"="test-mhc-r7qjm"
=== 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
I1115 03:35:22.849593   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqfzq" "namespace"="test-mhc-r7qjm" 
I1115 03:35:22.849694   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x7vdt" "namespace"="test-mhc-776sk" 
I1115 03:35:22.849722   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-swxpt" "namespace"="test-mhc-c74qj" 
I1115 03:35:22.849746   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s7nwq" "namespace"="test-mhc-52vqx" 
I1115 03:35:22.885260   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1115 03:35:23.008003   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s7nwq" "namespace"="test-mhc-52vqx" 
I1115 03:35:23.056333   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s7nwq" "namespace"="test-mhc-52vqx" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E1115 03:35:23.096603   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-52vqx/test-cluster-cjr5c"
E1115 03:35:23.099794   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-cjr5c\" not found" "controller"="cluster" "name"="test-cluster-cjr5c" "namespace"="test-mhc-52vqx"
I1115 03:35:23.103261   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gngbq" "namespace"="test-mhc-ldr6v" 
I1115 03:35:23.116778   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1115 03:35:23.234763   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gngbq" "namespace"="test-mhc-ldr6v" 
E1115 03:35:23.308566   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-ldr6v/test-cluster-m5dlq"
I1115 03:35:23.312996   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gngbq" "namespace"="test-mhc-ldr6v" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I1115 03:35:23.337265   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
inframachine created: test-mhc-machine-infra-6nlm2
machine created: test-mhc-machine-7k4tz
I1115 03:35:23.361149   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
node created: test-mhc-node-85bdh
E1115 03:35:23.460924   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-85bdh"
E1115 03:35:23.461784   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-85bdh, got []"  "node"="test-mhc-node-85bdh"
I1115 03:35:23.461809   10495 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-lgbtz/test-mhc-ptmvw/test-mhc-machine-7k4tz/"
I1115 03:35:23.461964   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" "noderef"="test-mhc-node-85bdh"
E1115 03:35:23.469839   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-85bdh"
E1115 03:35:23.469898   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-85bdh"
E1115 03:35:23.470124   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-85bdh, got []"  "node"="test-mhc-node-85bdh"
E1115 03:35:23.470159   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-85bdh, got []"  "node"="test-mhc-node-85bdh"
inframachine created: test-mhc-machine-infra-qtknq
machine created: test-mhc-machine-7t772
I1115 03:35:23.683207   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
I1115 03:35:23.683664   10495 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-lgbtz/test-mhc-ptmvw/test-mhc-machine-7t772/"
E1115 03:35:23.692328   10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-9vxb5"
node created: test-mhc-node-9vxb5
E1115 03:35:23.693011   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9vxb5, got []"  "node"="test-mhc-node-9vxb5"
I1115 03:35:23.696565   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" "noderef"="test-mhc-node-9vxb5"
I1115 03:35:23.721296   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
I1115 03:35:23.882428   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
I1115 03:35:23.884887   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
Cleaning up nodes, machines and infra machines.
I1115 03:35:23.894229   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
I1115 03:35:23.894637   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgbtz/test-mhc-ptmvw/test-mhc-machine-7k4tz/"
I1115 03:35:23.912799   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
I1115 03:35:23.913306   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgbtz/test-mhc-ptmvw/test-mhc-machine-7k4tz/"
I1115 03:35:23.913757   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgbtz/test-mhc-ptmvw/test-mhc-machine-7t772/"
E1115 03:35:23.960539   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lgbtz/test-cluster-2x6sv"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-2fhkp
E1115 03:35:24.112560   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
E1115 03:35:24.116502   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-ptmvw\" not found" "controller"="machinehealthcheck" "name"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz"
machine created: test-mhc-machine-xkmfd
E1115 03:35:24.122485   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-45dld/machine-reconcile-9r7v5"
E1115 03:35:25.112936   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:25.116777   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:25.173698   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1115 03:35:25.199259   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" 
I1115 03:35:25.199338   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:25.215586   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:25.216606   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 412 lines ...
I1115 03:35:26.103228   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.104927   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.106641   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.108406   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.110112   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.111802   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
E1115 03:35:26.113266   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:26.113439   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.115361   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.122471   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.124316   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.126058   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:26.127757   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 463 lines ...
I1115 03:35:27.122135   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:27.123842   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:27.125769   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:27.126329   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:27.127451   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:27.129562   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
E1115 03:35:27.129739   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:27.130372   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:27.130636   10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-xkmfd/"
I1115 03:35:27.139960   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:27.140332   10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-xkmfd/"
E1115 03:35:27.230256   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tq5kj, got []"  "node"="test-mhc-node-tq5kj"
node created: test-mhc-node-tq5kj
I1115 03:35:27.245886   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
inframachine created: test-mhc-machine-infra-9jtp8
I1115 03:35:27.267160   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
machine created: test-mhc-machine-6x6bk
I1115 03:35:27.278664   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 289 lines ...
I1115 03:35:28.115210   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.118049   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.121152   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.124111   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.127222   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.130006   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
E1115 03:35:28.131307   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:28.131959   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.134155   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.136392   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.138809   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.140940   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:28.143129   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 408 lines ...
I1115 03:35:29.156244   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.172915   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.174465   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.175691   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.176755   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.185086   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
E1115 03:35:29.186429   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:29.189321   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.191452   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.192610   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.197459   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.207886   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:29.209698   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 353 lines ...
I1115 03:35:30.189259   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.192964   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.195252   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.196278   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.198395   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.200673   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
E1115 03:35:30.201685   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:30.201749   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.202053   10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-6x6bk/"
I1115 03:35:30.211754   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.212204   10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-6x6bk/"
E1115 03:35:30.295077   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-scvw9, got []"  "node"="test-mhc-node-scvw9"
node created: test-mhc-node-scvw9
I1115 03:35:30.302863   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
inframachine created: test-mhc-machine-infra-tbjvz
machine created: test-mhc-machine-ch2cn
I1115 03:35:30.319202   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:30.324852   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 260 lines ...
I1115 03:35:31.196507   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.200142   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.210489   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.216028   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.219203   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.222927   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
E1115 03:35:31.224373   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:31.224474   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.227561   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.230302   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.233215   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.237926   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:31.241702   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 288 lines ...
I1115 03:35:32.304183   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.306434   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.308685   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.319131   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.320804   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.322311   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
E1115 03:35:32.323616   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:32.326049   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.328705   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.331433   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.333926   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.336429   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:32.338988   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
... skipping 247 lines ...
I1115 03:35:33.338423   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.345305   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.347388   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.349431   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.351695   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.360948   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.361682   10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/"
E1115 03:35:33.363376   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-74db8, got []"  "node"="test-mhc-node-74db8"
node created: test-mhc-node-74db8
E1115 03:35:33.376756   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:33.386443   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.387011   10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/"
Cleaning up nodes, machines and infra machines.
I1115 03:35:33.391594   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.392133   10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/test-mhc-node-74db8"
I1115 03:35:33.402283   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" 
I1115 03:35:33.402788   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/"
Cleaning up nodes, machines and infra machines.
I1115 03:35:33.453516   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "count"=2
I1115 03:35:33.453599   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "descendants"="Worker machines: test-mhc-machine-6x6bk,test-mhc-machine-ch2cn,test-mhc-machine-xkmfd" "indirect descendants count"=1
I1115 03:35:33.457586   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "count"=2
I1115 03:35:33.457646   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "descendants"="Worker machines: test-mhc-machine-ch2cn,test-mhc-machine-xkmfd,test-mhc-machine-6x6bk" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
... skipping 7 lines ...
I1115 03:35:33.679051   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:33.720014   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:33.802297   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:33.963343   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:34.284439   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:34.377298   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rrpnm" "machine"="test-mhc-machine-6x6bk" "namespace"="test-mhc-4rjqq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-scvw9"}
E1115 03:35:34.418163   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6x6bk\" not found" "controller"="machine" "name"="test-mhc-machine-6x6bk" "namespace"="test-mhc-4rjqq"
I1115 03:35:34.926129   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:35.431474   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:36.211349   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:36.431961   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rrpnm" "machine"="test-mhc-machine-ch2cn" "namespace"="test-mhc-4rjqq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-74db8"}
E1115 03:35:36.483250   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ch2cn\" not found" "controller"="machine" "name"="test-mhc-machine-ch2cn" "namespace"="test-mhc-4rjqq"
I1115 03:35:37.483856   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rrpnm" "machine"="test-mhc-machine-xkmfd" "namespace"="test-mhc-4rjqq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-tq5kj"}
E1115 03:35:37.529285   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xkmfd\" not found" "controller"="machine" "name"="test-mhc-machine-xkmfd" "namespace"="test-mhc-4rjqq"
E1115 03:35:38.471920   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4rjqq/test-cluster-rrpnm"
E1115 03:35:38.529677   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:38.772393   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.538260   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.545553   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:39.545981   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
node created: test-mhc-node-vrf7p
E1115 03:35:39.559264   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vrf7p, got []"  "node"="test-mhc-node-vrf7p"
I1115 03:35:39.563469   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.567196   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
inframachine created: test-mhc-machine-infra-lr5vr
machine created: test-mhc-machine-d5pxx
I1115 03:35:39.612218   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.626372   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.627497   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.631478   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.672633   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.754052   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:39.915483   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:40.236893   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:40.546580   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:40.879988   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:41.569985   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:41.578039   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:41.591888   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:41.599030   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:41.615346   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:41.617239   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:41.618207   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:41.646595   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:41.707229   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lw8k7, got []"  "node"="test-mhc-node-lw8k7"
node created: test-mhc-node-lw8k7
I1115 03:35:41.715791   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
inframachine created: test-mhc-machine-infra-rq6p6
I1115 03:35:41.733813   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:41.747014   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
machine created: test-mhc-machine-wf9dd
I1115 03:35:41.773369   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:42.161319   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:42.617648   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:43.629330   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:43.643475   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:43.650112   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:43.669218   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:43.676116   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:43.691353   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
I1115 03:35:43.697658   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:43.699853   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:43.721520   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
E1115 03:35:43.773234   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pgs6t, got []"  "node"="test-mhc-node-pgs6t"
node created: test-mhc-node-pgs6t
I1115 03:35:43.780018   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
Cleaning up nodes, machines and infra machines.
I1115 03:35:43.793855   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" 
Cleaning up nodes, machines and infra machines.
I1115 03:35:43.832546   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-wgntj" "namespace"="test-mhc-rj454" "count"=2
... skipping 5 lines ...
I1115 03:35:43.963962   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
inframachine created: test-mhc-machine-infra-p7bpv
I1115 03:35:43.998927   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-57q5f
I1115 03:35:44.016378   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:44.021997   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
E1115 03:35:44.700305   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:45.700857   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wgntj" "machine"="test-mhc-machine-kqxwz" "namespace"="test-mhc-rj454" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vrf7p"}
E1115 03:35:45.751842   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kqxwz\" not found" "controller"="machine" "name"="test-mhc-machine-kqxwz" "namespace"="test-mhc-rj454"
I1115 03:35:46.752400   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wgntj" "machine"="test-mhc-machine-d5pxx" "namespace"="test-mhc-rj454" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-lw8k7"}
E1115 03:35:46.790151   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-d5pxx\" not found" "controller"="machine" "name"="test-mhc-machine-d5pxx" "namespace"="test-mhc-rj454"
I1115 03:35:47.790630   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wgntj" "machine"="test-mhc-machine-wf9dd" "namespace"="test-mhc-rj454" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pgs6t"}
E1115 03:35:47.835476   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wf9dd\" not found" "controller"="machine" "name"="test-mhc-machine-wf9dd" "namespace"="test-mhc-rj454"
I1115 03:35:48.846898   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
E1115 03:35:48.853076   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:48.853108   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
E1115 03:35:48.853582   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rj454/test-cluster-wgntj"
E1115 03:35:48.936727   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8nclh, got []"  "node"="test-mhc-node-8nclh"
node created: test-mhc-node-8nclh
I1115 03:35:48.945168   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
inframachine created: test-mhc-machine-infra-77wxq
I1115 03:35:48.961410   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:48.962926   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
machine created: test-mhc-machine-n7djs
I1115 03:35:48.974138   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
E1115 03:35:49.853440   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:50.866606   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.874152   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.882029   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.888482   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.897595   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.904172   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.921215   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.937473   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.947246   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.963643   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
node created: test-mhc-node-d82k4
E1115 03:35:50.976405   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d82k4, got []"  "node"="test-mhc-node-d82k4"
I1115 03:35:50.980600   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:50.987892   10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-n7djs" "namespace"="test-mhc-r94v9" "noderef"="test-mhc-node-d82k4"
I1115 03:35:50.989123   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
inframachine created: test-mhc-machine-infra-pc2dq
machine created: test-mhc-machine-rwvbc
I1115 03:35:51.017536   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
... skipping 9 lines ...
I1115 03:35:51.238755   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:51.249948   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:51.252218   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-j8r6d" "machine"="test-mhc-machine-rwvbc" "namespace"="test-mhc-r94v9" "cause"="noderef is nil" "node"=null
Cleaning up nodes, machines and infra machines.
I1115 03:35:51.260159   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:51.262482   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:51.263028   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r94v9/test-mhc-cwt4t/test-mhc-machine-57q5f/"
I1115 03:35:51.293307   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:51.294017   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r94v9/test-mhc-cwt4t/test-mhc-machine-57q5f/"
I1115 03:35:51.294488   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r94v9/test-mhc-cwt4t/test-mhc-machine-n7djs/"
E1115 03:35:51.338118   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rwvbc\" not found" "controller"="machine" "name"="test-mhc-machine-rwvbc" "namespace"="test-mhc-r94v9"
I1115 03:35:51.346855   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "count"=2
I1115 03:35:51.346938   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "descendants"="Worker machines: test-mhc-machine-57q5f,test-mhc-machine-n7djs" "indirect descendants count"=0
I1115 03:35:51.350817   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "count"=2
I1115 03:35:51.350896   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "descendants"="Worker machines: test-mhc-machine-57q5f,test-mhc-machine-n7djs" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-r6css
machine created: test-mhc-machine-ktk5b
E1115 03:35:51.474522   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-cwt4t\" not found" "controller"="machinehealthcheck" "name"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9"
I1115 03:35:52.338696   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-j8r6d" "machine"="test-mhc-machine-57q5f" "namespace"="test-mhc-r94v9" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8nclh"}
E1115 03:35:52.386759   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-57q5f\" not found" "controller"="machine" "name"="test-mhc-machine-57q5f" "namespace"="test-mhc-r94v9"
I1115 03:35:52.474842   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:52.497057   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1115 03:35:52.614251   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" 
I1115 03:35:52.614320   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:52.614956   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:52.615548   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
... skipping 388 lines ...
I1115 03:35:53.439999   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.441939   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.443904   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.445858   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.448099   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.450099   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
E1115 03:35:53.451509   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-n7djs\" not found" "controller"="machine" "name"="test-mhc-machine-n7djs" "namespace"="test-mhc-r94v9"
I1115 03:35:53.452229   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.456638   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.458349   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.460039   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.461804   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:53.463533   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
... skipping 476 lines ...
I1115 03:35:54.457341   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.458872   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.460260   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.460794   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.462437   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.464258   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.464547   10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/"
E1115 03:35:54.464804   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:35:54.474048   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.474305   10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/"
node created: test-mhc-node-rxv4l
E1115 03:35:54.512720   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rxv4l, got []"  "node"="test-mhc-node-rxv4l"
E1115 03:35:54.512947   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rxv4l, got []"  "node"="test-mhc-node-rxv4l"
I1115 03:35:54.523538   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.537334   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.538255   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.548186   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.549655   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.549942   10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l"
I1115 03:35:54.562557   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.562940   10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l"
I1115 03:35:54.563561   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.563828   10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l"
Cleaning up nodes, machines and infra machines.
I1115 03:35:54.573994   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.574331   10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l"
I1115 03:35:54.575004   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.576243   10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/"
I1115 03:35:54.591478   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2fdr2" "namespace"="test-mhc-kf227" "descendants"="Worker machines: test-mhc-machine-ktk5b" "indirect descendants count"=1
I1115 03:35:54.595997   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2fdr2" "namespace"="test-mhc-kf227" "descendants"="Worker machines: test-mhc-machine-ktk5b" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I1115 03:35:54.727425   10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" "creating"=1 "need"=1
I1115 03:35:54.727479   10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" 
I1115 03:35:54.756248   10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-62njv-n8jfm\"" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" 
I1115 03:35:54.758367   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" 
I1115 03:35:54.816086   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:54.830400   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1115 03:35:54.850834   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
E1115 03:35:55.465319   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:35:55.851059   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
E1115 03:35:56.364796   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-r94v9/test-cluster-j8r6d"
I1115 03:35:56.465889   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2fdr2" "machine"="test-mhc-machine-ktk5b" "namespace"="test-mhc-kf227" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-rxv4l"}
E1115 03:35:56.516499   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ktk5b\" not found" "controller"="machine" "name"="test-mhc-machine-ktk5b" "namespace"="test-mhc-kf227"
I1115 03:35:56.852054   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:57.525205   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:57.525352   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" 
I1115 03:35:57.530479   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:57.531279   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" 
I1115 03:35:57.549415   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
... skipping 7 lines ...
I1115 03:35:57.579391   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:57.579439   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:57.852829   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:58.565900   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:58.565955   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.000790   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.001254   10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/"
I1115 03:35:59.009866   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.013961   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.014009   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.014089   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.014387   10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/"
I1115 03:35:59.025283   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.025341   10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.025644   10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/"
I1115 03:35:59.051238   10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.051280   10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.071438   10495 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" "machine"="mhc-ms-62njv-n8jfm"
I1115 03:35:59.077262   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.078373   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-48vfh" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" "cause"="noderef is nil" "node"=null
I1115 03:35:59.080144   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "count"=1
I1115 03:35:59.080206   10495 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-62njv"
I1115 03:35:59.080291   10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/"
I1115 03:35:59.087025   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "descendants"="Machine sets: mhc-ms-62njv;Worker machines: mhc-ms-62njv-n8jfm" "indirect descendants count"=1
I1115 03:35:59.092265   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.092585   10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/"
I1115 03:35:59.102403   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "descendants"="Worker machines: mhc-ms-62njv-n8jfm" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I1115 03:35:59.127410   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" 
I1115 03:35:59.314966   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
inframachine created: test-mhc-machine-infra-sxhf9
I1115 03:35:59.329893   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-48vfh" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" "cause"="cluster is being deleted" "node"=null
I1115 03:35:59.347965   10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-t2hqd
E1115 03:35:59.374937   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-62njv-n8jfm\" not found" "controller"="machine" "name"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn"
I1115 03:35:59.466803   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.467553   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.468176   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.471955   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.473708   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.475818   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
... skipping 48 lines ...
I1115 03:35:59.598393   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.600126   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.602988   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.604678   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.606453   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.608172   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
E1115 03:35:59.608655   10495 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kf227/test-cluster-2fdr2"
I1115 03:35:59.609869   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.611601   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.613323   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.615016   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.618329   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:35:59.620052   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
... skipping 323 lines ...
I1115 03:36:00.381198   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.383027   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.383958   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.385986   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.387880   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.388524   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
E1115 03:36:00.388860   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz"
I1115 03:36:00.452489   10495 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-t2hqd" "target"="test-mhc-69tm4/test-mhc-hdz4v/test-mhc-machine-t2hqd/"
E1115 03:36:00.466765   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4tqxf, got []"  "node"="test-mhc-node-4tqxf"
E1115 03:36:00.466996   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4tqxf, got []"  "node"="test-mhc-node-4tqxf"
node created: test-mhc-node-4tqxf
I1115 03:36:00.471543   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.476272   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.499901   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.508624   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.510827   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.514147   10495 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-t2hqd" "target"="test-mhc-69tm4/test-mhc-hdz4v/test-mhc-machine-t2hqd/test-mhc-node-4tqxf"
I1115 03:36:00.536478   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
Cleaning up nodes, machines and infra machines.
I1115 03:36:00.544717   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.547352   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.551531   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" 
I1115 03:36:00.558197   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-smrql" "namespace"="test-mhc-69tm4" "descendants"="Worker machines: test-mhc-machine-t2hqd" "indirect descendants count"=1
... skipping 332 lines ...
I1115 03:36:01.448560   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.450576   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.452863   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.454652   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.456803   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.458596   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
E1115 03:36:01.460259   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-t2hqd\" not found" "controller"="machine" "name"="test-mhc-machine-t2hqd" "namespace"="test-mhc-69tm4"
I1115 03:36:01.460403   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.462190   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.463965   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.465711   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.467548   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:01.469333   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
... skipping 535 lines ...
I1115 03:36:02.451336   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.453218   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.455101   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.456842   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.458446   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.460126   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
E1115 03:36:02.460610   10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz"
I1115 03:36:02.462019   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.463668   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.465280   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.466942   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.468734   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:02.470459   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
... skipping 562 lines ...
I1115 03:36:03.463672   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.465206   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.467358   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.468025   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.469112   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.470841   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.478069   10495 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-lgtt8" "target"="test-mhc-ktqg6/test-mhc-6r8z4/test-mhc-machine-lgtt8/"
I1115 03:36:03.487932   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
E1115 03:36:03.536658   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-snffj, got []"  "node"="test-mhc-node-snffj"
node created: test-mhc-node-snffj
E1115 03:36:03.536824   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-snffj, got []"  "node"="test-mhc-node-snffj"
E1115 03:36:03.536860   10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-snffj, got []"  "node"="test-mhc-node-snffj"
I1115 03:36:03.543266   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.560495   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.569046   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.572251   10495 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-lgtt8" "target"="test-mhc-ktqg6/test-mhc-6r8z4/test-mhc-machine-lgtt8/test-mhc-node-snffj"
I1115 03:36:03.589145   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.600242   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.824641   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.828059   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
Cleaning up nodes, machines and infra machines.
I1115 03:36:03.838705   10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" 
I1115 03:36:03.841491   10495 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-lgtt8" "target"="test-mhc-ktqg6/test-mhc-6r8z4/test-mhc-machine-lgtt8/"
I1115 03:36:03.843052   10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6n5gv" "machine"="test-mhc-machine-lgtt8" "namespace"="test-mhc-ktqg6" "cause"="no control plane members" "node"={"name":"test-mhc-node-snffj"}
I1115 03:36:03.853048   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "count"=1
I1115 03:36:03.853110   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "descendants"="Worker machines: test-mhc-machine-lgtt8" "indirect descendants count"=0
I1115 03:36:03.856260   10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "count"=1
I1115 03:36:03.856385   10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "descendants"="Worker machines: test-mhc-machine-lgtt8" "indirect descendants count"=0
--- PASS: TestMachineHealthCheck_Reconcile (42.07s)
... skipping 15 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.46s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.29s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E1115 03:36:03.863132   10495 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
E1115 03:36:03.864432   10495 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
E1115 03:36:03.866007   10495 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E1115 03:36:03.866252   10495 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
E1115 03:36:03.866618   10495 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I1115 03:36:03.871655   10495 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I1115 03:36:03.872534   10495 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E1115 03:36:03.875006   10495 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.01s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
fatal error: concurrent map read and map write

goroutine 1168 [running]:
runtime.throw(0x19d1121, 0x21)
	/usr/local/go/src/runtime/panic.go:774 +0x72 fp=0xc0011cae58 sp=0xc0011cae28 pc=0x4314c2
runtime.mapaccess2(0x177f3a0, 0xc000281650, 0xc0011caf18, 0x203000, 0x203000)
	/usr/local/go/src/runtime/map.go:470 +0x278 fp=0xc0011caea0 sp=0xc0011cae58 pc=0x40fda8
... skipping 4 lines ...
k8s.io/apimachinery/pkg/runtime/serializer/json.(*Serializer).Decode(0xc00013d400, 0xc000ada000, 0x108, 0x200, 0xc000c7b500, 0x0, 0x0, 0x40df46, 0xc000c7b500, 0x30, ...)
	/home/prow/go/pkg/mod/k8s.io/apimachinery@v0.17.9/pkg/runtime/serializer/json/json.go:258 +0x57a fp=0xc0011cb3c0 sp=0xc0011cb098 pc=0xa049aa
k8s.io/apimachinery/pkg/runtime.WithoutVersionDecoder.Decode(0x1c211a0, 0xc00013d400, 0xc000ada000, 0x108, 0x200, 0xc000c7b500, 0x0, 0x0, 0x40e7b8, 0x30, ...)
	/home/prow/go/pkg/mod/k8s.io/apimachinery@v0.17.9/pkg/runtime/helper.go:252 +0x97 fp=0xc0011cb458 sp=0xc0011cb3c0 pc=0x87ef67
k8s.io/apimachinery/pkg/runtime.(*WithoutVersionDecoder).Decode(0xc000ff6d60, 0xc000ada000, 0x108, 0x200, 0xc000c7b500, 0x0, 0x0, 0xc000c78a80, 0xc000c78980, 0xc000c54000, ...)
	<autogenerated>:1 +0x9f fp=0xc0011cb4d0 sp=0xc0011cb458 pc=0x88ad3f
k8s.io/client-go/rest.Result.Error(0xc000ada000, 0x108, 0x200, 0xc000f10440, 0x10, 0x1c21000, 0xc0000eeaa0, 0x194, 0x1c227c0, 0xc000ff6d60, ...)
	/home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/rest/request.go:1218 +0x11a fp=0xc0011cb560 sp=0xc0011cb4d0 pc=0xa2dfaa
k8s.io/client-go/rest.Result.Into(0xc000ada000, 0x108, 0x200, 0xc000f10440, 0x10, 0x1c21000, 0xc0000eeaa0, 0x194, 0x1c227c0, 0xc000ff6d60, ...)
	/home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/rest/request.go:1172 +0x3b3 fp=0xc0011cb628 sp=0xc0011cb560 pc=0xa2dde3
sigs.k8s.io/controller-runtime/pkg/client.(*typedClient).PatchStatus(0xc00013d5e0, 0x1c61e80, 0xc0000d6010, 0x1c311a0, 0xc000e6a280, 0x1c31820, 0xc000c2a680, 0x0, 0x0, 0x0, ...)
	/home/prow/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.5.14/pkg/client/typed_client.go:209 +0x48e fp=0xc0011cb760 sp=0xc0011cb628 pc=0x120074e
sigs.k8s.io/controller-runtime/pkg/client.(*statusWriter).Patch(0xc00013e0d0, 0x1c61e80, 0xc0000d6010, 0x1c311a0, 0xc000e6a280, 0x1c31820, 0xc000c2a680, 0x0, 0x0, 0x0, ...)
... skipping 2915 lines ...
k8s.io/client-go/tools/cache.(*controller).Run(0xc0009f0300, 0xc000b62120)
	/home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/controller.go:125 +0x2fd
k8s.io/client-go/tools/cache.(*sharedIndexInformer).Run(0xc000136360, 0xc000b62120)
	/home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/shared_informer.go:331 +0x47f
created by sigs.k8s.io/controller-runtime/pkg/cache/internal.(*specificInformersMap).Start.func1
	/home/prow/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.5.14/pkg/cache/internal/informers_map.go:137 +0x122
FAIL	sigs.k8s.io/cluster-api/controllers	58.915s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
--- PASS: TestCloneTemplateResourceNotFound (0.00s)
... skipping 255 lines ...
I1115 03:35:18.547373   10837 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I1115 03:35:18.547399   10837 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I1115 03:35:18.547599   10837 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I1115 03:35:18.548775   10837 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I1115 03:35:18.548997   10837 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=33551
I1115 03:35:18.549221   10837 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E1115 03:35:20.758263   10837 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-5l8vd/test-cluster"
•E1115 03:35:21.213188   10837 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-drqtr/test-cluster"
•E1115 03:35:21.783290   10837 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:39659/?timeout=50ms: dial tcp 127.0.0.1:39659: connect: connection refused"  "cluster"="cluster-cache-test-l9jvc/test-cluster"
•I1115 03:35:22.018638   10837 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I1115 03:35:22.118995   10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I1115 03:35:22.119066   10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I1115 03:35:22.319692   10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I1115 03:35:22.346031   10837 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I1115 03:35:22.646457   10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I1115 03:35:22.646523   10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I1115 03:35:22.646618   10837 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I1115 03:35:23.170171   10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E1115 03:35:23.170341   10837 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1115 03:35:23.170393   10837 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-149011369/tls.crt: no such file or directory"  
I1115 03:35:23.170397   10837 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1115 03:35:23.219813   10837 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1alpha3.Cluster: Get http://127.0.0.1:44683/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:44683: connect: connection refused


Ran 5 of 5 Specs in 16.958 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.96s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	17.119s
?   	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
I1115 03:35:32.287212   11586 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
E1115 03:35:32.288452   11586 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
I1115 03:35:32.289075   11586 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I1115 03:35:32.289259   11586 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
I1115 03:35:48.702532   11586 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
I1115 03:35:48.702782   11586 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: 1668483317
Will run 1 of 1 specs

E1115 03:35:48.724637   11586 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-9jd96s\" not found" "kubeadmControlPlane"="kcp-foo-9jd96s" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.018 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I1115 03:35:48.726002   11586 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-r51bxl" "kubeadmControlPlane"="kcp-foo-r51bxl" "namespace"="test" 
I1115 03:35:50.440750   11586 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-r51bxl" "kubeadmControlPlane"="kcp-foo-r51bxl" "namespace"="test" "needRollout"=["kcp-foo-r51bxl-vsbpj"]
I1115 03:35:50.440921   11586 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-r51bxl" "kubeadmControlPlane"="kcp-foo-r51bxl" "namespace"="test" "failures"="[machine kcp-foo-r51bxl-8f6gg does not have APIServerPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have ControllerManagerPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have SchedulerPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have EtcdPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.72s)
... skipping 60 lines ...
==================================
Random Seed: 1668483316
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: 1668483316
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E1115 03:35:31.622973   11541 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"  
E1115 03:35:39.946458   11541 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"  
E1115 03:35:48.932720   11541 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"  
E1115 03:36:00.062999   11541 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"  
E1115 03:36:16.536223   11541 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"  
E1115 03:36:29.544773   11541 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"  
E1115 03:36:47.192149   11541 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"  
E1115 03:37:08.115600   11541 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"  
E1115 03:37:39.132082   11541 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"  
E1115 03:38:24.289291   11541 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
E1115 03:38:24.298579   11541 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1115 03:38:24.298631   11541 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-330002394/tls.crt: no such file or directory"  
I1115 03:38:24.298665   11541 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.195s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I1115 03:35:41.768356   11899 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I1115 03:35:41.867270   11899 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I1115 03:35:41.968856   11899 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I1115 03:35:41.969710   11899 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I1115 03:35:41.969778   11899 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I1115 03:35:42.050570   11899 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-r5av6c"} 
•E1115 03:35:42.087128   11899 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"
I1115 03:35:43.150203   11899 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-mepdtz"} 
•E1115 03:35:43.191111   11899 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"

------------------------------
• Failure [11.093 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E1115 03:35:54.283633   11899 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"
E1115 03:35:55.425176   11899 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"
•2022/11/15 03:35:56 http: TLS handshake error from 127.0.0.1:36984: EOF
E1115 03:35:56.459687   11899 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"
E1115 03:35:57.474798   11899 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"
•I1115 03:35:57.475560   11899 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I1115 03:35:57.475599   11899 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E1115 03:35:57.475687   11899 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1115 03:35:57.475716   11899 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-721962873/tls.crt: no such file or directory"  
I1115 03:35:57.475688   11899 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

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

Ran 5 of 5 Specs in 30.717 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (30.72s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	30.813s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E1115 03:35:32.518614   12110 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 ...
•I1115 03:35:45.111821   12110 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1115 03:35:45.134556   12110 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1115 03:35:45.136520   12110 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I1115 03:35:45.164547   12110 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1115 03:35:45.170351   12110 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}}}
I1115 03:35:45.192125   12110 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E1115 03:35:45.194639   12110 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1115 03:35:45.194695   12110 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-690329012/tls.crt: no such file or directory"  
E1115 03:35:45.194716   12110 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1115 03:35:45.194749   12110 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-690329012/tls.crt: no such file or directory"  
I1115 03:35:45.194853   12110 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 12.691 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (12.69s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	12.940s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 201 lines ...
I1115 03:36:08.332541   15081 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I1115 03:36:08.332663   15081 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I1115 03:36:08.333524   15081 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I1115 03:36:08.333761   15081 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I1115 03:36:08.333833   15081 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=45245
••••••••••••••I1115 03:36:09.086963   15081 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1115 03:36:09.087235   15081 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E1115 03:36:09.087308   15081 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-889420093/tls.crt: no such file or directory"  


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