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

No Test Failures!


Error lines from build-log.txt

... skipping 774 lines ...
I0805 15:03:22.273149    8476 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0805 15:03:22.274456    8476 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0805 15:03:22.276191    8476 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0805 15:03:22.292925    8476 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=34267
I0805 15:03:23.004750    8476 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" 
•I0805 15:03:23.022599    8476 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0805 15:03:23.022749    8476 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:03:23.022815    8476 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-066042043/tls.crt: no such file or directory"  
E0805 15:03:23.022838    8476 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:03:23.022858    8476 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-066042043/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 15.166 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (15.17s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	47.680s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.02s)
=== 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 ...
I0805 15:03:11.755196   10597 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0805 15:03:11.755595   10597 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
I0805 15:03:11.755665   10597 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0805 15:03:11.755661   10597 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0805 15:03:11.755761   10597 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
I0805 15:03:11.755740   10597 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
2022/08/05 15:03:12 http: TLS handshake error from 127.0.0.1:39638: 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
I0805 15:03:12.055417   10597 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"
I0805 15:03:12.059706   10597 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
I0805 15:03:12.117072   10597 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
I0805 15:03:12.121337   10597 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"
E0805 15:03:12.121873   10597 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
I0805 15:03:12.122517   10597 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
I0805 15:03:12.500869   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0805 15:03:12.506427   10597 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0805 15:03:12.521229   10597 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-dstf9" "namespace"="test-machine-watches-jddhz" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0805 15:03:12.521326   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0805 15:03:12.631951   10597 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-dstf9" "namespace"="test-machine-watches-jddhz" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0805 15:03:12.632050   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0805 15:03:12.732637   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-dstf9" "namespace"="test-machine-watches-jddhz" "noderef"="node-1"
E0805 15:03:12.743902   10597 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0805 15:03:12.743952   10597 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0805 15:03:12.797938   10597 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-dstf9\" in namespace \"test-machine-watches-jddhz\", requeuing: requeue in 1s"  
E0805 15:03:12.811690   10597 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-dstf9\" in namespace \"test-machine-watches-jddhz\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-dstf9\" in namespace \"test-machine-watches-jddhz\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-dstf9" "namespace"="test-machine-watches-jddhz"
--- PASS: TestWatches (0.79s)
=== 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
I0805 15:03:13.056852   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-4xzhr" "namespace"="test-machine-watches-jddhz" "count"=1
I0805 15:03:13.056945   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-4xzhr" "namespace"="test-machine-watches-jddhz" "descendants"="Worker machines: machine-created-dstf9" "indirect descendants count"=0
I0805 15:03:13.078347   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-4xzhr" "namespace"="test-machine-watches-jddhz" "count"=1
I0805 15:03:13.078413   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-4xzhr" "namespace"="test-machine-watches-jddhz" "descendants"="Worker machines: machine-created-dstf9" "indirect descendants count"=0
I0805 15:03:13.812303   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4xzhr" "machine"="machine-created-dstf9" "namespace"="test-machine-watches-jddhz" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"3e3555d1-d4f8-4ac4-85e3-753881259e34","apiVersion":"v1"}
E0805 15:03:13.873245   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-dstf9\" not found" "controller"="machine" "name"="machine-created-dstf9" "namespace"="test-machine-watches-jddhz"
E0805 15:03:14.949628   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-zpzg4\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-zt5jp\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-zt5jp: secrets \"machine-reconcile-zt5jp-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-zpzg4" "namespace"="default"
I0805 15:03:15.950466   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zt5jp" "machine"="machine-created-zpzg4" "namespace"="default" "cause"="noderef is nil" "node"=null
I0805 15:03:15.991955   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zt5jp" "machine"="machine-created-zpzg4" "namespace"="default" "cause"="noderef is nil" "node"=null
I0805 15:03:16.020179   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zt5jp" "machine"="machine-created-zpzg4" "namespace"="default" "cause"="noderef is nil" "node"=null
E0805 15:03:16.063679   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-zpzg4\" not found" "controller"="machine" "name"="machine-created-zpzg4" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.17s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.17s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.02s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0805 15:03:16.109507   10597 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"
E0805 15:03:16.112695   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-zt5jp\" not found" "controller"="cluster" "name"="machine-reconcile-zt5jp" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0805 15:03:16.115983   10597 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0805 15:03:16.120544   10597 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.01s)
... skipping 112 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0805 15:03:16.415404   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzsnj" "namespace"="test-mhc-29pxm" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0805 15:03:16.468056   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0805 15:03:16.468171   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-5c9m4\" not found"  "cluster"="test-mhc-29pxm/test-cluster-5c9m4"
E0805 15:03:16.582756   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-fzsnj\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-fzsnj\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-fzsnj" "namespace"="test-mhc-29pxm"
=== 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
I0805 15:03:17.591298   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzsnj" "namespace"="test-mhc-29pxm" 
I0805 15:03:17.591475   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s47mp" "namespace"="test-mhc-x9r4c" 
I0805 15:03:17.591627   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-75q62" "namespace"="test-mhc-7qhhn" 
I0805 15:03:17.591673   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p845w" "namespace"="test-mhc-dj7td" 
I0805 15:03:17.650409   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0805 15:03:17.798809   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p845w" "namespace"="test-mhc-dj7td" 
I0805 15:03:17.806013   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p845w" "namespace"="test-mhc-dj7td" 
I0805 15:03:17.898432   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p845w" "namespace"="test-mhc-dj7td" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0805 15:03:17.916941   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-dj7td/test-cluster-7wc5z"
E0805 15:03:17.920988   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-7wc5z\" not found" "controller"="cluster" "name"="test-cluster-7wc5z" "namespace"="test-mhc-dj7td"
I0805 15:03:18.083570   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mxqwd" "namespace"="test-mhc-w8t7g" 
I0805 15:03:18.131244   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0805 15:03:18.176703   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mxqwd" "namespace"="test-mhc-w8t7g" 
I0805 15:03:18.207536   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mxqwd" "namespace"="test-mhc-w8t7g" 
E0805 15:03:18.289495   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-w8t7g/test-cluster-2psff"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0805 15:03:18.296530   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mxqwd" "namespace"="test-mhc-w8t7g" 
I0805 15:03:18.317326   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
inframachine created: test-mhc-machine-infra-k78cw
I0805 15:03:18.408068   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-lllg7
I0805 15:03:18.452474   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.468479   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.470103   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.477061   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.480671   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.489583   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.491204   10597 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-cznw6/test-mhc-tshpc/test-mhc-machine-lllg7/"
I0805 15:03:18.529164   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.529586   10597 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-cznw6/test-mhc-tshpc/test-mhc-machine-lllg7/"
I0805 15:03:18.546192   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.546893   10597 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-cznw6/test-mhc-tshpc/test-mhc-machine-lllg7/"
I0805 15:03:18.551562   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.551897   10597 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-cznw6/test-mhc-tshpc/test-mhc-machine-lllg7/"
node created: test-mhc-node-6f84n
E0805 15:03:18.555367   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6f84n, got []"  "node"="test-mhc-node-6f84n"
E0805 15:03:18.555598   10597 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6f84n"
I0805 15:03:18.558752   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-lllg7" "namespace"="test-mhc-cznw6" "noderef"="test-mhc-node-6f84n"
E0805 15:03:18.568792   10597 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6f84n"
E0805 15:03:18.568844   10597 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6f84n"
E0805 15:03:18.568792   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6f84n, got []"  "node"="test-mhc-node-6f84n"
E0805 15:03:18.568879   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6f84n, got []"  "node"="test-mhc-node-6f84n"
I0805 15:03:18.569944   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
inframachine created: test-mhc-machine-infra-pmvbq
machine created: test-mhc-machine-mr52x
I0805 15:03:18.595080   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.607831   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.609329   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
... skipping 42 lines ...
I0805 15:03:18.783365   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.791442   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.793239   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.798272   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.800401   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.803620   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.804363   10597 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-cznw6/test-mhc-tshpc/test-mhc-machine-mr52x/"
I0805 15:03:18.836733   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.837208   10597 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-cznw6/test-mhc-tshpc/test-mhc-machine-mr52x/"
I0805 15:03:18.889358   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:18.889890   10597 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-cznw6/test-mhc-tshpc/test-mhc-machine-mr52x/"
E0805 15:03:18.894431   10597 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-p7g26"
node created: test-mhc-node-p7g26
E0805 15:03:18.895614   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-p7g26, got []"  "node"="test-mhc-node-p7g26"
I0805 15:03:18.903430   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
E0805 15:03:18.942422   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-jddhz/machine-reconcile-4xzhr"
I0805 15:03:19.073156   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:19.075106   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
Cleaning up nodes, machines and infra machines.
I0805 15:03:19.086892   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:19.087366   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cznw6/test-mhc-tshpc/test-mhc-machine-lllg7/"
I0805 15:03:19.169176   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:19.169917   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cznw6/test-mhc-tshpc/test-mhc-machine-lllg7/"
I0805 15:03:19.170491   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cznw6/test-mhc-tshpc/test-mhc-machine-mr52x/"
I0805 15:03:19.208040   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-njttm" "namespace"="test-mhc-cznw6" "count"=2
I0805 15:03:19.208189   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-njttm" "namespace"="test-mhc-cznw6" "descendants"="Worker machines: test-mhc-machine-lllg7,test-mhc-machine-mr52x" "indirect descendants count"=0
I0805 15:03:19.211605   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
I0805 15:03:19.212353   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cznw6/test-mhc-tshpc/test-mhc-machine-lllg7/"
I0805 15:03:19.212883   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-cznw6/test-mhc-tshpc/test-mhc-machine-mr52x/"
I0805 15:03:19.217539   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-njttm" "namespace"="test-mhc-cznw6" "count"=2
I0805 15:03:19.217596   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-njttm" "namespace"="test-mhc-cznw6" "descendants"="Worker machines: test-mhc-machine-lllg7,test-mhc-machine-mr52x" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
I0805 15:03:19.241724   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tshpc" "namespace"="test-mhc-cznw6" 
inframachine created: test-mhc-machine-infra-9lkdd
I0805 15:03:19.303603   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
machine created: test-mhc-machine-cwcmh
I0805 15:03:19.340921   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0805 15:03:19.379643   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-lllg7\" in namespace \"test-mhc-cznw6\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-lllg7" "namespace"="test-mhc-cznw6"
I0805 15:03:19.415393   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:19.416485   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:19.418220   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:19.420061   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:19.421894   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:19.423646   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
... skipping 398 lines ...
I0805 15:03:20.444823   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.447588   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.449612   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.455083   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.457387   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.459310   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
E0805 15:03:20.459436   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mr52x\" not found" "controller"="machine" "name"="test-mhc-machine-mr52x" "namespace"="test-mhc-cznw6"
I0805 15:03:20.461188   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.462930   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.464649   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.466855   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.469256   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:20.471245   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
... skipping 419 lines ...
I0805 15:03:21.479777   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.480455   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.482179   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.484616   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.486466   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.486548   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-njttm" "machine"="test-mhc-machine-lllg7" "namespace"="test-mhc-cznw6" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-6f84n","uid":"bebc8f18-2ee7-4609-a7e4-6b828ae9a11c","apiVersion":"v1"}
I0805 15:03:21.486736   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-cwcmh/"
I0805 15:03:21.502865   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.503227   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-cwcmh/"
E0805 15:03:21.550483   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lllg7\" not found" "controller"="machine" "name"="test-mhc-machine-lllg7" "namespace"="test-mhc-cznw6"
node created: test-mhc-node-46jkc
E0805 15:03:21.565023   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-46jkc, got []"  "node"="test-mhc-node-46jkc"
E0805 15:03:21.565023   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-46jkc, got []"  "node"="test-mhc-node-46jkc"
I0805 15:03:21.574393   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
inframachine created: test-mhc-machine-infra-wmlqf
machine created: test-mhc-machine-x8ntr
I0805 15:03:21.593775   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.599865   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:21.601058   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
... skipping 354 lines ...
I0805 15:03:22.610662   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.612248   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.613697   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.614877   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.619122   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.622608   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.623157   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
I0805 15:03:22.645942   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.646373   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
I0805 15:03:22.660840   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.661351   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
I0805 15:03:22.676992   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.677499   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
I0805 15:03:22.685835   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.686464   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
E0805 15:03:22.699939   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zr7qc, got []"  "node"="test-mhc-node-zr7qc"
E0805 15:03:22.699939   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zr7qc, got []"  "node"="test-mhc-node-zr7qc"
node created: test-mhc-node-zr7qc
I0805 15:03:22.706611   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.708684   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
I0805 15:03:22.714794   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
inframachine created: test-mhc-machine-infra-48pks
machine created: test-mhc-machine-rcrmc
I0805 15:03:22.752849   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.766534   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.767073   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
I0805 15:03:22.782861   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.783438   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
I0805 15:03:22.784876   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.785394   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
I0805 15:03:22.816601   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.817235   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
E0805 15:03:22.836839   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wgqxz, got []"  "node"="test-mhc-node-wgqxz"
node created: test-mhc-node-wgqxz
E0805 15:03:22.837371   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wgqxz, got []"  "node"="test-mhc-node-wgqxz"
I0805 15:03:22.848834   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.849444   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
I0805 15:03:22.863958   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.865036   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
I0805 15:03:22.875897   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.876527   10597 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-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/test-mhc-node-wgqxz"
Cleaning up nodes, machines and infra machines.
I0805 15:03:22.904738   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.905559   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
Cleaning up nodes, machines and infra machines.
I0805 15:03:22.940648   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.942583   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-mpjzl/test-mhc-jzlnk/test-mhc-machine-cwcmh/"
I0805 15:03:22.961193   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
I0805 15:03:22.978392   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
I0805 15:03:22.989179   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:22.989856   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-mpjzl/test-mhc-jzlnk/test-mhc-machine-x8ntr/"
I0805 15:03:22.990348   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-mpjzl/test-mhc-jzlnk/test-mhc-machine-rcrmc/"
I0805 15:03:22.990826   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-mpjzl/test-mhc-jzlnk/test-mhc-machine-cwcmh/"
I0805 15:03:22.996665   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jsrs4" "namespace"="test-mhc-mpjzl" "count"=3
I0805 15:03:22.997164   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jsrs4" "namespace"="test-mhc-mpjzl" "descendants"="Worker machines: test-mhc-machine-cwcmh,test-mhc-machine-x8ntr,test-mhc-machine-rcrmc" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0805 15:03:23.001287   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jzlnk" "namespace"="test-mhc-mpjzl" 
I0805 15:03:23.009764   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jsrs4" "namespace"="test-mhc-mpjzl" "count"=3
I0805 15:03:23.009856   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jsrs4" "namespace"="test-mhc-mpjzl" "descendants"="Worker machines: test-mhc-machine-cwcmh,test-mhc-machine-x8ntr,test-mhc-machine-rcrmc" "indirect descendants count"=0
I0805 15:03:23.032354   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
inframachine created: test-mhc-machine-infra-zpqw9
E0805 15:03:23.049554   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-rcrmc\" in namespace \"test-mhc-mpjzl\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-rcrmc" "namespace"="test-mhc-mpjzl"
I0805 15:03:23.053829   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-2gj7c
I0805 15:03:23.179759   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:23.180579   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:23.190458   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:23.231697   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:23.314120   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:23.475125   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:23.796284   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:24.050212   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jsrs4" "machine"="test-mhc-machine-cwcmh" "namespace"="test-mhc-mpjzl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-46jkc"}
E0805 15:03:24.159773   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cwcmh\" not found" "controller"="machine" "name"="test-mhc-machine-cwcmh" "namespace"="test-mhc-mpjzl"
E0805 15:03:24.230858   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-cznw6/test-cluster-njttm"
I0805 15:03:24.437735   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:25.160508   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jsrs4" "machine"="test-mhc-machine-x8ntr" "namespace"="test-mhc-mpjzl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zr7qc"}
E0805 15:03:25.269050   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-x8ntr\" not found" "controller"="machine" "name"="test-mhc-machine-x8ntr" "namespace"="test-mhc-mpjzl"
I0805 15:03:25.722858   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:26.270253   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jsrs4" "machine"="test-mhc-machine-rcrmc" "namespace"="test-mhc-mpjzl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wgqxz"}
E0805 15:03:26.335136   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rcrmc\" not found" "controller"="machine" "name"="test-mhc-machine-rcrmc" "namespace"="test-mhc-mpjzl"
I0805 15:03:27.348166   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.360699   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
node created: test-mhc-node-98bnn
E0805 15:03:27.407013   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-98bnn, got []"  "node"="test-mhc-node-98bnn"
E0805 15:03:27.409064   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-98bnn, got []"  "node"="test-mhc-node-98bnn"
I0805 15:03:27.409993   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.427458   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
inframachine created: test-mhc-machine-infra-n2b6j
machine created: test-mhc-machine-2sz5x
I0805 15:03:27.494250   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.538217   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.547561   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.549497   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.554930   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.574569   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
node created: test-mhc-node-zwthc
E0805 15:03:27.594974   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zwthc, got []"  "node"="test-mhc-node-zwthc"
E0805 15:03:27.595058   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zwthc, got []"  "node"="test-mhc-node-zwthc"
I0805 15:03:27.625898   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
inframachine created: test-mhc-machine-infra-6f77m
I0805 15:03:27.641077   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
machine created: test-mhc-machine-fwpp7
I0805 15:03:27.663357   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.679868   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.693521   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.701933   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.722174   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.728209   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.776684   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
E0805 15:03:27.781838   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vn8c8, got []"  "node"="test-mhc-node-vn8c8"
E0805 15:03:27.781846   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vn8c8, got []"  "node"="test-mhc-node-vn8c8"
node created: test-mhc-node-vn8c8
I0805 15:03:27.786390   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-fwpp7" "namespace"="test-mhc-jmmc2" "noderef"="test-mhc-node-vn8c8"
I0805 15:03:27.787557   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
E0805 15:03:27.802860   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vn8c8, got []"  "node"="test-mhc-node-vn8c8"
E0805 15:03:27.802925   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vn8c8, got []"  "node"="test-mhc-node-vn8c8"
E0805 15:03:27.803660   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vn8c8, got []"  "node"="test-mhc-node-vn8c8"
E0805 15:03:27.803721   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vn8c8, got []"  "node"="test-mhc-node-vn8c8"
I0805 15:03:27.804115   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
Cleaning up nodes, machines and infra machines.
I0805 15:03:27.836398   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
Cleaning up nodes, machines and infra machines.
I0805 15:03:27.869183   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:27.885470   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ss5tj" "namespace"="test-mhc-jmmc2" "count"=2
I0805 15:03:27.885579   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ss5tj" "namespace"="test-mhc-jmmc2" "descendants"="Worker machines: test-mhc-machine-2gj7c,test-mhc-machine-2sz5x,test-mhc-machine-fwpp7" "indirect descendants count"=1
I0805 15:03:27.889836   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ss5tj" "namespace"="test-mhc-jmmc2" "count"=2
I0805 15:03:27.889905   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ss5tj" "namespace"="test-mhc-jmmc2" "descendants"="Worker machines: test-mhc-machine-2gj7c,test-mhc-machine-2sz5x,test-mhc-machine-fwpp7" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
E0805 15:03:27.897936   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-vmfwh\" not found" "controller"="machinehealthcheck" "name"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2"
inframachine created: test-mhc-machine-infra-rqqpx
E0805 15:03:28.043160   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mpjzl/test-cluster-jsrs4"
machine created: test-mhc-machine-bhslf
I0805 15:03:28.056309   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ss5tj" "machine"="test-mhc-machine-2sz5x" "namespace"="test-mhc-jmmc2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zwthc"}
E0805 15:03:28.106723   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2sz5x\" not found" "controller"="machine" "name"="test-mhc-machine-2sz5x" "namespace"="test-mhc-jmmc2"
I0805 15:03:28.898243   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vmfwh" "namespace"="test-mhc-jmmc2" 
I0805 15:03:28.898363   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:28.922898   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0805 15:03:29.044649   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:29.107979   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ss5tj" "machine"="test-mhc-machine-2gj7c" "namespace"="test-mhc-jmmc2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-98bnn"}
E0805 15:03:29.170594   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2gj7c\" not found" "controller"="machine" "name"="test-mhc-machine-2gj7c" "namespace"="test-mhc-jmmc2"
I0805 15:03:30.180217   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:30.186347   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:30.187895   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ss5tj" "machine"="test-mhc-machine-fwpp7" "namespace"="test-mhc-jmmc2" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-vn8c8","uid":"1f48876d-5ee1-45eb-9f6e-0edf108b5bd5","apiVersion":"v1"}
E0805 15:03:30.249551   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fwpp7\" not found" "controller"="machine" "name"="test-mhc-machine-fwpp7" "namespace"="test-mhc-jmmc2"
E0805 15:03:30.283275   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mmbjq, got []"  "node"="test-mhc-node-mmbjq"
node created: test-mhc-node-mmbjq
E0805 15:03:30.283940   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mmbjq, got []"  "node"="test-mhc-node-mmbjq"
I0805 15:03:30.295288   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
inframachine created: test-mhc-machine-infra-khd9t
machine created: test-mhc-machine-thxd8
I0805 15:03:30.331414   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:30.355377   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.263849   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
... skipping 2 lines ...
I0805 15:03:31.288929   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.297777   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.309607   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.314714   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.337501   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
node created: test-mhc-node-57gtt
E0805 15:03:31.344247   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-57gtt, got []"  "node"="test-mhc-node-57gtt"
E0805 15:03:31.345547   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-57gtt, got []"  "node"="test-mhc-node-57gtt"
I0805 15:03:31.356762   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.370595   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-thxd8" "namespace"="test-mhc-vpgh4" "noderef"="test-mhc-node-57gtt"
inframachine created: test-mhc-machine-infra-jzljr
I0805 15:03:31.395270   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.404894   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.411277   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
... skipping 6 lines ...
Cleaning up nodes, machines and infra machines.
I0805 15:03:31.531933   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.558123   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
Cleaning up nodes, machines and infra machines.
I0805 15:03:31.572525   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.574574   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.575169   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vpgh4/test-mhc-xq7gp/test-mhc-machine-bhslf/"
I0805 15:03:31.613698   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:31.614328   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vpgh4/test-mhc-xq7gp/test-mhc-machine-bhslf/"
I0805 15:03:31.614766   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vpgh4/test-mhc-xq7gp/test-mhc-machine-thxd8/"
E0805 15:03:31.628805   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-thxd8\" in namespace \"test-mhc-vpgh4\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-thxd8" "namespace"="test-mhc-vpgh4"
I0805 15:03:31.642213   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9b5tj" "namespace"="test-mhc-vpgh4" "count"=3
I0805 15:03:31.642310   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9b5tj" "namespace"="test-mhc-vpgh4" "descendants"="Worker machines: test-mhc-machine-bhslf,test-mhc-machine-thxd8,test-mhc-machine-qrztp" "indirect descendants count"=0
I0805 15:03:31.666086   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9b5tj" "namespace"="test-mhc-vpgh4" "count"=3
I0805 15:03:31.666167   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9b5tj" "namespace"="test-mhc-vpgh4" "descendants"="Worker machines: test-mhc-machine-bhslf,test-mhc-machine-thxd8,test-mhc-machine-qrztp" "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-v7brs
machine created: test-mhc-machine-7mmfz
E0805 15:03:31.777195   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-xq7gp\" not found" "controller"="machinehealthcheck" "name"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4"
I0805 15:03:32.629427   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9b5tj" "machine"="test-mhc-machine-bhslf" "namespace"="test-mhc-vpgh4" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mmbjq"}
E0805 15:03:32.693920   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-bhslf\" not found" "controller"="machine" "name"="test-mhc-machine-bhslf" "namespace"="test-mhc-vpgh4"
I0805 15:03:32.777530   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:32.796266   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0805 15:03:32.909879   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jmmc2/test-cluster-ss5tj"
I0805 15:03:32.923142   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xq7gp" "namespace"="test-mhc-vpgh4" 
I0805 15:03:32.923238   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:32.924826   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:32.925895   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:32.927009   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:32.928839   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
... skipping 279 lines ...
I0805 15:03:33.762135   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.764009   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.766216   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.768714   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.770898   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.772875   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
E0805 15:03:33.774014   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qrztp\" not found" "controller"="machine" "name"="test-mhc-machine-qrztp" "namespace"="test-mhc-vpgh4"
I0805 15:03:33.774608   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.776354   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.778046   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.779730   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.781718   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:33.783963   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
... skipping 398 lines ...
I0805 15:03:34.822830   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.824909   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.826784   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.828569   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.830397   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.834497   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
E0805 15:03:34.839198   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-thxd8\" not found" "controller"="machine" "name"="test-mhc-machine-thxd8" "namespace"="test-mhc-vpgh4"
I0805 15:03:34.840972   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.843242   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.845415   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.847850   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.850468   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:34.852693   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
... skipping 431 lines ...
I0805 15:03:35.860011   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.860760   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.862478   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.865590   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.867804   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.869537   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.870868   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/"
I0805 15:03:35.885097   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.885419   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/"
I0805 15:03:35.889425   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.889874   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/"
I0805 15:03:35.907789   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
E0805 15:03:35.910622   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bv6vn, got []"  "node"="test-mhc-node-bv6vn"
E0805 15:03:35.910923   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bv6vn, got []"  "node"="test-mhc-node-bv6vn"
node created: test-mhc-node-bv6vn
I0805 15:03:35.911101   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/"
I0805 15:03:35.924970   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.925381   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/"
I0805 15:03:35.934649   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-7mmfz" "namespace"="test-mhc-7z75x" "noderef"="test-mhc-node-bv6vn"
I0805 15:03:35.938457   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.960497   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.972273   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.972732   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/test-mhc-node-bv6vn"
I0805 15:03:35.997776   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:35.998363   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/test-mhc-node-bv6vn"
I0805 15:03:35.999645   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:36.000493   10597 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-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/test-mhc-node-bv6vn"
Cleaning up nodes, machines and infra machines.
I0805 15:03:36.031681   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:36.032117   10597 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-7z75x/test-mhc-lq2hn/test-mhc-machine-7mmfz/"
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0805 15:03:36.067793   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-bht42" "namespace"="test-mhc-7z75x" "count"=1
I0805 15:03:36.067875   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-bht42" "namespace"="test-mhc-7z75x" "descendants"="Worker machines: test-mhc-machine-7mmfz" "indirect descendants count"=0
I0805 15:03:36.091517   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-bht42" "namespace"="test-mhc-7z75x" "count"=1
I0805 15:03:36.091585   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-bht42" "namespace"="test-mhc-7z75x" "descendants"="Worker machines: test-mhc-machine-7mmfz" "indirect descendants count"=0
I0805 15:03:36.094640   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-bht42" "machine"="test-mhc-machine-7mmfz" "namespace"="test-mhc-7z75x" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-bv6vn","uid":"512f75e0-a97f-43c8-96c6-47a9e608013c","apiVersion":"v1"}
E0805 15:03:36.159805   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7mmfz\" not found" "controller"="machine" "name"="test-mhc-machine-7mmfz" "namespace"="test-mhc-7z75x"
E0805 15:03:36.200164   10597 machinehealthcheck_controller.go:167] controllers/MachineHealthCheck "msg"="Failed to reconcile MachineHealthCheck" "error"="failed to patch unhealthy machine status for machine: test-mhc-7z75x/test-mhc-machine-7mmfz: [Machine.cluster.x-k8s.io \"test-mhc-machine-7mmfz\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-7mmfz\" not found]" "cluster"="test-cluster-bht42" 
E0805 15:03:36.200786   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch unhealthy machine status for machine: test-mhc-7z75x/test-mhc-machine-7mmfz: [Machine.cluster.x-k8s.io \"test-mhc-machine-7mmfz\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-7mmfz\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x"
I0805 15:03:36.298638   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" "creating"=1 "need"=1
I0805 15:03:36.298710   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" 
I0805 15:03:36.317586   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-8vl8h-hz2wh\"" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" 
E0805 15:03:36.686129   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vpgh4/test-cluster-9b5tj"
I0805 15:03:37.170858   10597 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" 
I0805 15:03:37.174930   10597 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" 
I0805 15:03:37.201069   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lq2hn" "namespace"="test-mhc-7z75x" 
I0805 15:03:37.201178   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l49mv" "namespace"="test-mhc-nh95x" 
I0805 15:03:37.207473   10597 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:37.207520   10597 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
... skipping 3 lines ...
I0805 15:03:37.260583   10597 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:37.260645   10597 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:37.271206   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l49mv" "namespace"="test-mhc-nh95x" 
I0805 15:03:38.240665   10597 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:38.240719   10597 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.000615   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l49mv" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.001278   10597 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-nh95x/test-mhc-l49mv/mhc-ms-8vl8h-hz2wh/"
I0805 15:03:39.010673   10597 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.016051   10597 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.016129   10597 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.019748   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l49mv" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.020125   10597 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-nh95x/test-mhc-l49mv/mhc-ms-8vl8h-hz2wh/"
I0805 15:03:39.024774   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l49mv" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.025158   10597 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-nh95x/test-mhc-l49mv/mhc-ms-8vl8h-hz2wh/"
I0805 15:03:39.025422   10597 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.037919   10597 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.038462   10597 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.049566   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-n98ct" "namespace"="test-mhc-nh95x" "count"=1
I0805 15:03:39.049652   10597 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-n98ct" "namespace"="test-mhc-nh95x" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-8vl8h"
I0805 15:03:39.050876   10597 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-8vl8h" "namespace"="test-mhc-nh95x" "machine"="mhc-ms-8vl8h-hz2wh"
I0805 15:03:39.056634   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n98ct" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" "cause"="cluster is being deleted" "node"=null
I0805 15:03:39.056898   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l49mv" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.057246   10597 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-nh95x/test-mhc-l49mv/mhc-ms-8vl8h-hz2wh/"
I0805 15:03:39.065808   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l49mv" "namespace"="test-mhc-nh95x" 
I0805 15:03:39.068911   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n98ct" "namespace"="test-mhc-nh95x" "descendants"="Machine sets: mhc-ms-8vl8h;Worker machines: mhc-ms-8vl8h-hz2wh" "indirect descendants count"=1
I0805 15:03:39.079849   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n98ct" "namespace"="test-mhc-nh95x" "descendants"="Worker machines: mhc-ms-8vl8h-hz2wh" "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
I0805 15:03:39.259355   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n98ct" "machine"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x" "cause"="cluster is being deleted" "node"=null
E0805 15:03:39.313614   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-8vl8h-hz2wh\" not found" "controller"="machine" "name"="mhc-ms-8vl8h-hz2wh" "namespace"="test-mhc-nh95x"
I0805 15:03:39.331121   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
inframachine created: test-mhc-machine-infra-hrkjd
I0805 15:03:39.357421   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-x92d7
I0805 15:03:39.491796   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:39.493277   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
... skipping 296 lines ...
I0805 15:03:40.323220   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.324611   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.325224   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.326305   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.327947   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.329589   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
E0805 15:03:40.372927   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rq6bw, got []"  "node"="test-mhc-node-rq6bw"
node created: test-mhc-node-rq6bw
E0805 15:03:40.373161   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rq6bw, got []"  "node"="test-mhc-node-rq6bw"
E0805 15:03:40.373214   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rq6bw, got []"  "node"="test-mhc-node-rq6bw"
I0805 15:03:40.380855   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-x92d7" "namespace"="test-mhc-gkvt5" "noderef"="test-mhc-node-rq6bw"
I0805 15:03:40.461743   10597 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-x92d7" "target"="test-mhc-gkvt5/test-mhc-4dpx4/test-mhc-machine-x92d7/"
I0805 15:03:40.485429   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.526384   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.535178   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.542026   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.546951   10597 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-x92d7" "target"="test-mhc-gkvt5/test-mhc-4dpx4/test-mhc-machine-x92d7/test-mhc-node-rq6bw"
I0805 15:03:40.580310   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.587316   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
Cleaning up nodes, machines and infra machines.
I0805 15:03:40.597535   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.610999   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.624316   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-s6v5z" "namespace"="test-mhc-gkvt5" "count"=1
I0805 15:03:40.624648   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-s6v5z" "namespace"="test-mhc-gkvt5" "descendants"="Worker machines: test-mhc-machine-x92d7" "indirect descendants count"=0
I0805 15:03:40.626179   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4dpx4" "namespace"="test-mhc-gkvt5" 
I0805 15:03:40.630384   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-s6v5z" "namespace"="test-mhc-gkvt5" "count"=1
I0805 15:03:40.630465   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-s6v5z" "namespace"="test-mhc-gkvt5" "descendants"="Worker machines: test-mhc-machine-x92d7" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
E0805 15:03:40.766500   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-x92d7\" in namespace \"test-mhc-gkvt5\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-x92d7" "namespace"="test-mhc-gkvt5"
I0805 15:03:40.778627   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
inframachine created: test-mhc-machine-infra-rjv7t
I0805 15:03:40.804637   10597 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-j4vrt
I0805 15:03:40.829886   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:40.837228   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
... skipping 111 lines ...
I0805 15:03:41.096924   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.098945   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.100660   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.102441   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.104344   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.106431   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
E0805 15:03:41.106787   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7z75x/test-cluster-bht42"
I0805 15:03:41.108630   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.110777   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.114975   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.117127   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.119058   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.121084   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
... skipping 262 lines ...
I0805 15:03:41.813873   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.815732   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.817590   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.820729   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.828916   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.831836   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
E0805 15:03:41.832382   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-x92d7\" not found" "controller"="machine" "name"="test-mhc-machine-x92d7" "namespace"="test-mhc-gkvt5"
I0805 15:03:41.834285   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.836138   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.838332   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.840122   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.841951   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:41.843786   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
... skipping 369 lines ...
I0805 15:03:42.839924   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.841745   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.843642   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.844340   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.845484   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.849375   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.858508   10597 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-j4vrt" "target"="test-mhc-9pbhl/test-mhc-w2rfk/test-mhc-machine-j4vrt/"
I0805 15:03:42.882711   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.893386   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.899940   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.915509   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
node created: test-mhc-node-9vn7q
E0805 15:03:42.946526   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9vn7q, got []"  "node"="test-mhc-node-9vn7q"
E0805 15:03:42.946926   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9vn7q, got []"  "node"="test-mhc-node-9vn7q"
E0805 15:03:42.947162   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9vn7q, got []"  "node"="test-mhc-node-9vn7q"
I0805 15:03:42.951656   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:42.961816   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-j4vrt" "namespace"="test-mhc-9pbhl" "noderef"="test-mhc-node-9vn7q"
I0805 15:03:42.971991   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.216745   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.220332   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.234295   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.246201   10597 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-j4vrt" "target"="test-mhc-9pbhl/test-mhc-w2rfk/test-mhc-machine-j4vrt/test-mhc-node-9vn7q"
I0805 15:03:43.291165   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.298221   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.310078   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.339401   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
Cleaning up nodes, machines and infra machines.
I0805 15:03:43.369289   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
I0805 15:03:43.381061   10597 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-j4vrt" "target"="test-mhc-9pbhl/test-mhc-w2rfk/test-mhc-machine-j4vrt/"
I0805 15:03:43.384930   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-nx459" "namespace"="test-mhc-9pbhl" "count"=1
I0805 15:03:43.385027   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nx459" "namespace"="test-mhc-9pbhl" "descendants"="Worker machines: test-mhc-machine-j4vrt" "indirect descendants count"=0
I0805 15:03:43.398242   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-nx459" "namespace"="test-mhc-9pbhl" "count"=1
I0805 15:03:43.398317   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nx459" "namespace"="test-mhc-9pbhl" "descendants"="Worker machines: test-mhc-machine-j4vrt" "indirect descendants count"=0
I0805 15:03:43.420513   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-nx459" "machine"="test-mhc-machine-j4vrt" "namespace"="test-mhc-9pbhl" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-9vn7q","uid":"d90a56f2-4527-44de-b672-7de3debc162b","apiVersion":"v1"}
--- PASS: TestMachineHealthCheck_Reconcile (27.14s)
... 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.55s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.79s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0805 15:03:43.425337   10597 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
E0805 15:03:43.427103   10597 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
E0805 15:03:43.430206   10597 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0805 15:03:43.430799   10597 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
E0805 15:03:43.431536   10597 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.01s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0805 15:03:43.436377   10597 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0805 15:03:43.437310   10597 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0805 15:03:43.443454   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-w2rfk\" not found" "controller"="machinehealthcheck" "name"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl"
E0805 15:03:43.444856   10597 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
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0805 15:03:43.465601   10597 machineset_controller.go:151]  "msg"="Failed to reconcile MachineSet" "error"="failed to calculate MachineSet's Status: failed to calculate status for MachineSet default/machineset1: invalid label key \"--$-invalid\": name part must consist of alphanumeric characters, '-', '_' or '.', and must start and end with an alphanumeric character (e.g. 'MyName',  or 'my.name',  or '123-abc', regex used for validation is '([A-Za-z0-9][-A-Za-z0-9_.]*)?[A-Za-z0-9]')" "machineset"="machineset1" "namespace"="default" 
--- PASS: TestMachineSetReconcile (0.00s)
    --- PASS: TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion (0.00s)
    --- PASS: TestMachineSetReconcile/records_event_if_reconcile_fails (0.00s)
=== RUN   TestMachineSetToMachines
=== RUN   TestMachineSetToMachines/should_return_empty_request_when_controller_is_set
=== RUN   TestMachineSetToMachines/should_return_nil_if_machine_has_no_owner_reference
... skipping 8 lines ...
--- PASS: TestAdoptOrphan (0.00s)
=== RUN   TestHasMatchingLabels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_has_empty_selector
=== RUN   TestHasMatchingLabels/machine_set_has_bad_selector
E0805 15:03:43.467263   10597 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1659711778
Will run 16 of 16 specs

E0805 15:03:43.516767   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j4vrt\" not found" "controller"="machine" "name"="test-mhc-machine-j4vrt" "namespace"="test-mhc-9pbhl"
I0805 15:03:43.632863   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-96hhb" "namespace"="ms-test" "creating"=2 "need"=2
I0805 15:03:43.632929   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-96hhb" "namespace"="ms-test" 
I0805 15:03:43.657930   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-96hhb-2km4b\"" "machineset"="ms-96hhb" "namespace"="ms-test" 
I0805 15:03:43.658006   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-96hhb" "namespace"="ms-test" 
I0805 15:03:43.684235   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-96hhb-46bkd\"" "machineset"="ms-96hhb" "namespace"="ms-test" 
I0805 15:03:43.808539   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-96hhb" "namespace"="ms-test" "creating"=1 "need"=2
I0805 15:03:43.808591   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-96hhb" "namespace"="ms-test" 
I0805 15:03:43.850550   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-96hhb-hlkbq\"" "machineset"="ms-96hhb" "namespace"="ms-test" 
E0805 15:03:43.935638   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:43.935941   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:43.936236   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:44.058627   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:44.058712   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:44.058738   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:44.058766   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:44.059007   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:44.059048   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-2km4b-7fsn5, got []"  "node"="ms-96hhb-2km4b-7fsn5"
E0805 15:03:44.121447   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-hlkbq-dx95p, got []"  "node"="ms-96hhb-hlkbq-dx95p"
E0805 15:03:44.121649   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-hlkbq-dx95p, got []"  "node"="ms-96hhb-hlkbq-dx95p"
E0805 15:03:44.122194   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-hlkbq-dx95p, got []"  "node"="ms-96hhb-hlkbq-dx95p"
E0805 15:03:44.125134   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-nh95x/test-cluster-n98ct"
E0805 15:03:44.230123   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-hlkbq-dx95p, got []"  "node"="ms-96hhb-hlkbq-dx95p"
E0805 15:03:44.230196   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-hlkbq-dx95p, got []"  "node"="ms-96hhb-hlkbq-dx95p"
E0805 15:03:44.230516   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-hlkbq-dx95p, got []"  "node"="ms-96hhb-hlkbq-dx95p"
E0805 15:03:44.230570   10597 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-96hhb-hlkbq-dx95p, got []"  "node"="ms-96hhb-hlkbq-dx95p"
I0805 15:03:44.368738   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-96hhb-2km4b,ms-96hhb-hlkbq" "indirect descendants count"=2
•I0805 15:03:44.378405   10597 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"
I0805 15:03:44.380299   10597 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0805 15:03:44.381217   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-96hhb-2km4b,ms-96hhb-hlkbq" "indirect descendants count"=2
I0805 15:03:44.383025   10597 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"
I0805 15:03:44.385001   10597 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
... skipping 16 lines ...
•I0805 15:03:44.415152   10597 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"
I0805 15:03:44.417372   10597 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"
I0805 15:03:44.443350   10597 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0805 15:03:44.443573   10597 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
I0805 15:03:44.443842   10597 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w2rfk" "namespace"="test-mhc-9pbhl" 
•I0805 15:03:44.447467   10597 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0805 15:03:44.453223   10597 machine_controller.go:494]  "msg"="Error creating a remote client while deleting Machine, won't retry" "error"="failed to create REST configuration for Cluster default/test-cluster: invalid configuration: no configuration has been provided" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" 
••E0805 15:03:44.610454   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-xr72b\" not found" "controller"="cluster" "name"="test1-xr72b" "namespace"="default"
E0805 15:03:45.653005   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gkvt5/test-cluster-s6v5z"
•I0805 15:03:45.738856   10597 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-dbthl" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0805 15:03:45.876739   10597 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-dbthl" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0805 15:03:45.884297   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
E0805 15:03:46.931307   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
•E0805 15:03:47.964618   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-nw659\" not found" "controller"="cluster" "name"="test3-nw659" "namespace"="default"
E0805 15:03:48.965563   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
E0805 15:03:49.997255   10597 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9pbhl/test-cluster-nx459"
E0805 15:03:49.998032   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
•I0805 15:03:50.998577   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-96hhb-hlkbq,ms-96hhb-2km4b" "indirect descendants count"=2
E0805 15:03:51.011731   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-vmb4w: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-vmb4w" "namespace"="default"
E0805 15:03:52.012630   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
E0805 15:03:53.035848   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-vmb4w: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-vmb4w" "namespace"="default"
•E0805 15:03:54.036661   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
E0805 15:03:55.037624   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-vmb4w: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-vmb4w" "namespace"="default"
E0805 15:03:56.058763   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
I0805 15:03:56.196379   10597 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dn7ps" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0805 15:03:56.225390   10597 machine_controller_noderef.go:73] controllers/Machine "msg"="Failed to retrieve Node by ProviderID" "error"="the cache is not started, can not read objects" "machine"="test6-dn7ps" "namespace"="default" 
E0805 15:03:56.279866   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\", the cache is not started, can not read objects]" "controller"="machine" "name"="test6-dn7ps" "namespace"="default"
E0805 15:03:57.059612   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-vmb4w: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-vmb4w" "namespace"="default"
I0805 15:03:57.304583   10597 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dn7ps" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0805 15:03:57.304914   10597 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-dn7ps" "namespace"="default" "noderef"="id-node-1"
E0805 15:03:57.354818   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="machine" "name"="test6-dn7ps" "namespace"="default"
I0805 15:03:58.060173   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-96hhb-2km4b,ms-96hhb-hlkbq" "indirect descendants count"=2
E0805 15:03:58.065836   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
•I0805 15:03:58.173523   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0805 15:03:58.173594   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:58.200545   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-mwn24-6657c7fddb-h9wmx\"" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:58.200628   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:58.214559   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-mwn24-6657c7fddb-7nx9v\"" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
E0805 15:03:58.242630   10597 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-mwn24-6657c7fddb\" not found" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
E0805 15:03:58.242799   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-mwn24-6657c7fddb\" not found" "controller"="machineset" "name"="md-mwn24-6657c7fddb" "namespace"="md-test"
I0805 15:03:58.355680   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-xxkzp" "machine"="test6-dn7ps" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"746bd5fc-d4ae-4bb9-8c0a-f0165d472211","apiVersion":"v1"}
E0805 15:03:58.411601   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dn7ps\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dn7ps" "namespace"="default"
E0805 15:03:59.067252   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-vmb4w: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-vmb4w" "namespace"="default"
I0805 15:03:59.250004   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "creating"=3 "need"=3
I0805 15:03:59.250092   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:59.266977   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 3 with name \"md-mwn24-6657c7fddb-szr5c\"" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:59.267042   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:59.279817   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 3 with name \"md-mwn24-6657c7fddb-l6ctq\"" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:59.279883   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 3 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:59.292265   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 3 of 3 with name \"md-mwn24-6657c7fddb-47c24\"" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" 
I0805 15:03:59.303636   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0805 15:03:59.303698   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" 
I0805 15:03:59.317390   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-mwn24-cdfc6fd6c-pwgvh\"" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" 
I0805 15:03:59.459714   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-xxkzp" "machine"="test6-dn7ps" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"746bd5fc-d4ae-4bb9-8c0a-f0165d472211","apiVersion":"v1"}
E0805 15:03:59.460924   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dn7ps\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dn7ps" "namespace"="default"
E0805 15:03:59.537167   10597 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-mwn24-cdfc6fd6c-pwgvh-lnzlr for machine md-test/md-mwn24-cdfc6fd6c-pwgvh: the cache is not started, can not read objects" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" 
I0805 15:03:59.584728   10597 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0805 15:03:59.584846   10597 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0805 15:03:59.593168   10597 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "machine"="md-mwn24-6657c7fddb-l6ctq"
I0805 15:03:59.711422   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0805 15:03:59.711480   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" 
I0805 15:03:59.729493   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-mwn24-cdfc6fd6c-6m2bk\"" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" 
I0805 15:04:00.022058   10597 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0805 15:04:00.022116   10597 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0805 15:04:00.027845   10597 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "machine"="md-mwn24-6657c7fddb-47c24"
I0805 15:04:00.067989   10597 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-xxkzp" "namespace"="default" "count"=1
I0805 15:04:00.068104   10597 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-xxkzp" "namespace"="default" "descendants"="Control plane machines: test6-dn7ps" "indirect descendants count"=0
E0805 15:04:00.087244   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-dbthl: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-dbthl" "namespace"="default"
I0805 15:04:00.171299   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0805 15:04:00.171378   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" 
I0805 15:04:00.186326   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-mwn24-cdfc6fd6c-cr6bg\"" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" 
I0805 15:04:00.413204   10597 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0805 15:04:00.413260   10597 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0805 15:04:00.419319   10597 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-mwn24-6657c7fddb" "namespace"="md-test" "machine"="md-mwn24-6657c7fddb-szr5c"
... skipping 2 lines ...
I0805 15:04:00.525274   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0805 15:04:00.525349   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" 
I0805 15:04:00.553297   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-mwn24-74d45c49c5-tb84b\"" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" 
I0805 15:04:00.553405   10597 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-mwn24-6657c7fddb-7nx9v" "namespace"="md-test" 
I0805 15:04:00.553449   10597 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-mwn24-6657c7fddb-7nx9v" "namespace"="md-test" 
I0805 15:04:00.603489   10597 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-xxkzp" "machine"="test6-dn7ps" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"746bd5fc-d4ae-4bb9-8c0a-f0165d472211","apiVersion":"v1"}
E0805 15:04:00.604329   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-dn7ps\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-dn7ps" "namespace"="default"
I0805 15:04:00.782477   10597 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0805 15:04:00.782553   10597 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0805 15:04:00.787097   10597 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "machine"="md-mwn24-cdfc6fd6c-pwgvh"
I0805 15:04:00.898817   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0805 15:04:00.898898   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" 
I0805 15:04:00.915660   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-mwn24-74d45c49c5-jwq97\"" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" 
I0805 15:04:01.045630   10597 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0805 15:04:01.045671   10597 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0805 15:04:01.051303   10597 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-mwn24-cdfc6fd6c" "namespace"="md-test" "machine"="md-mwn24-cdfc6fd6c-6m2bk"
I0805 15:04:01.074466   10597 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0805 15:04:01.074534   10597 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" 
E0805 15:04:01.088015   10597 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-vmb4w: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-vmb4w" "namespace"="default"
I0805 15:04:01.095779   10597 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-mwn24-74d45c49c5-hdmqm\"" "machineset"="md-mwn24-74d45c49c5" "namespace"="md-test" 
•

Ran 16 of 16 Specs in 17.721 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (17.72s)
PASS
Tearing down test suite
I0805 15:04:01.190805   10597 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0805 15:04:01.190852   10597 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0805 15:04:01.191096   10597 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0805 15:04:01.191141   10597 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0805 15:04:01.191168   10597 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0805 15:04:01.191200   10597 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0805 15:04:01.191229   10597 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0805 15:04:01.191286   10597 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0805 15:04:01.191385   10597 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-186279681/tls.crt: no such file or directory"  
E0805 15:04:01.233570   10597 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:39965/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1311&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:39965: connect: connection refused
E0805 15:04:01.233571   10597 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:39965/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1311&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:39965: connect: connection refused
E0805 15:04:01.233596   10597 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:39965/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1311&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:39965: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	62.463s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
I0805 15:03:14.748943   11010 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0805 15:03:15.218910   11010 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0805 15:03:15.232151   11010 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}}}
I0805 15:03:15.332741   11010 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0805 15:03:15.332848   11010 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0805 15:03:15.532238   11010 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0805 15:03:17.567550   11010 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-bqjv5/test-cluster"
•E0805 15:03:18.064099   11010 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-6k8mj/test-cluster"
•E0805 15:03:18.601201   11010 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:45085/?timeout=50ms: dial tcp 127.0.0.1:45085: connect: connection refused"  "cluster"="cluster-cache-test-99tk2/test-cluster"
•E0805 15:03:18.812578   11010 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0805 15:03:18.812668   11010 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0805 15:03:18.812669   11010 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-869708156/tls.crt: no such file or directory"  
E0805 15:03:18.888115   11010 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:35531/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:35531: connect: connection refused


Ran 5 of 5 Specs in 18.424 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (18.42s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	18.625s
?   	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
I0805 15:03:28.523213   11721 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
E0805 15:03:28.524677   11721 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
I0805 15:03:28.525400   11721 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0805 15:03:28.525560   11721 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
I0805 15:03:46.676700   11721 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
I0805 15:03:46.676871   11721 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: 1659711793
Will run 1 of 1 specs

E0805 15:03:46.736069   11721 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-ncah4k\" not found" "kubeadmControlPlane"="kcp-foo-ncah4k" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.053 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.05s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0805 15:03:46.738310   11721 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-339j28" "kubeadmControlPlane"="kcp-foo-339j28" "namespace"="test" 
I0805 15:03:48.356298   11721 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-339j28" "kubeadmControlPlane"="kcp-foo-339j28" "namespace"="test" "needRollout"=["kcp-foo-339j28-hrrzx"]
I0805 15:03:48.356540   11721 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-339j28" "kubeadmControlPlane"="kcp-foo-339j28" "namespace"="test" "failures"="[machine kcp-foo-339j28-xxd9r does not have APIServerPodHealthy condition, machine kcp-foo-339j28-xxd9r does not have ControllerManagerPodHealthy condition, machine kcp-foo-339j28-xxd9r does not have SchedulerPodHealthy condition, machine kcp-foo-339j28-xxd9r does not have EtcdPodHealthy condition, machine kcp-foo-339j28-xxd9r does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.62s)
PASS
E0805 15:03:48.357608   11721 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:03:48.357669   11721 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-450841077/tls.crt: no such file or directory"  
E0805 15:03:48.357690   11721 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0805 15:03:48.357669   11721 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0805 15:03:48.357708   11721 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-450841077/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	34.737s
I0805 15:03:28.889923   11703 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0805 15:03:28.890190   11703 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0805 15:03:28.890345   11703 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0805 15:03:28.890384   11703 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0805 15:03:28.890594   11703 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 52 lines ...
==================================
Random Seed: 1659711793
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: 1659711793
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0805 15:03:31.169087   11703 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"  
E0805 15:03:39.492252   11703 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"  
E0805 15:03:48.478247   11703 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"  
E0805 15:03:59.608532   11703 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"  
E0805 15:04:16.081993   11703 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"  
E0805 15:04:29.090790   11703 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"  
E0805 15:04:46.738316   11703 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"  
E0805 15:05:07.661762   11703 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"  
E0805 15:05:38.678361   11703 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"  
E0805 15:06:23.835670   11703 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
E0805 15:06:23.846390   11703 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:06:23.846458   11703 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-037525665/tls.crt: no such file or directory"  
E0805 15:06:23.846477   11703 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:06:23.846494   11703 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-037525665/tls.crt: no such file or directory"  
I0805 15:06:23.846669   11703 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	190.424s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0805 15:03:39.117999   12021 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0805 15:03:39.217819   12021 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0805 15:03:39.318406   12021 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0805 15:03:39.318479   12021 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0805 15:03:39.318707   12021 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0805 15:03:39.411246   12021 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-qdm569"} 
E0805 15:03:39.441072   12021 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"
•I0805 15:03:40.498184   12021 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-jo3t5k"} 
E0805 15:03:40.548128   12021 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"
•E0805 15:03:41.618086   12021 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0805 15:03:42.673618   12021 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"
•E0805 15:03:43.912020   12021 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"
E0805 15:03:44.940611   12021 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"
••I0805 15:03:45.956920   12021 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0805 15:03:45.957101   12021 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0805 15:03:45.957169   12021 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0805 15:03:45.957497   12021 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"


Ran 5 of 5 Specs in 21.402 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (21.40s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	21.493s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.01s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.02s)
=== 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
E0805 15:03:27.086418   12161 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 91 lines ...
•I0805 15:03:40.999092   12161 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0805 15:03:41.025101   12161 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0805 15:03:41.055142   12161 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0805 15:03:41.057252   12161 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0805 15:03:41.095997   12161 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0805 15:03:41.137133   12161 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0805 15:03:41.139981   12161 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:03:41.140024   12161 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-981720104/tls.crt: no such file or directory"  
E0805 15:03:41.140043   12161 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:03:41.140061   12161 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-981720104/tls.crt: no such file or directory"  
I0805 15:03:41.140467   12161 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0805 15:03:41.196233   12161 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


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

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 24 lines ...
STEP: Creating a new patch helper
STEP: Updating the object spec
STEP: Updating the object status
STEP: Setting Ready condition
STEP: Patching the object
•I0805 15:04:08.034716   15122 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0805 15:04:08.034894   15122 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0805 15:04:08.034946   15122 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-784749441/tls.crt: no such file or directory"  



Summarizing 1 Failure:

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

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