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

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I0801 15:02:16.246307    8515 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0801 15:02:16.246505    8515 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0801 15:02:16.247563    8515 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0801 15:02:16.247773    8515 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=41689
I0801 15:02:16.248258    8515 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0801 15:02:17.199643    8515 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" 
•E0801 15:02:17.215404    8515 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0801 15:02:17.215548    8515 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0801 15:02:17.215572    8515 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-210604169/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 14.978 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.98s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	55.376s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1388 lines ...
I0801 15:02:01.890885   10604 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0801 15:02:01.890922   10604 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0801 15:02:02.090068   10604 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}},"status":{"bootstrapReady":false,"infrastructureReady":false}}}
I0801 15:02:02.090185   10604 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}},"status":{"bootstrapReady":false,"infrastructureReady":false}}}
I0801 15:02:02.090248   10604 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0801 15:02:02.090321   10604 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
2022/08/01 15:02:02 http: TLS handshake error from 127.0.0.1:41796: 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
I0801 15:02:02.288575   10604 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"
I0801 15:02:02.289872   10604 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
... skipping 115 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0801 15:02:02.346704   10604 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
I0801 15:02:02.348548   10604 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"
E0801 15:02:02.348893   10604 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
I0801 15:02:02.349406   10604 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0801 15:02:02.778452   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0801 15:02:02.879092   10604 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0801 15:02:02.887964   10604 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-rlg7f" "namespace"="test-machine-watches-gclp7" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0801 15:02:02.888089   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0801 15:02:03.007373   10604 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-rlg7f" "namespace"="test-machine-watches-gclp7" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0801 15:02:03.007502   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0801 15:02:03.108138   10604 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-rlg7f" "namespace"="test-machine-watches-gclp7" "noderef"="node-1"
E0801 15:02:03.121995   10604 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0801 15:02:03.122100   10604 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0801 15:02:03.156732   10604 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-rlg7f" "namespace"="test-machine-watches-gclp7" "noderef"="node-1"
E0801 15:02:03.171261   10604 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-rlg7f\" in namespace \"test-machine-watches-gclp7\", requeuing: requeue in 1s"  
E0801 15:02:03.186811   10604 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-rlg7f\" in namespace \"test-machine-watches-gclp7\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-rlg7f\" in namespace \"test-machine-watches-gclp7\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-rlg7f" "namespace"="test-machine-watches-gclp7"
--- PASS: TestWatches (0.86s)
=== 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
I0801 15:02:03.407402   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-2rt9k" "namespace"="test-machine-watches-gclp7" "count"=1
I0801 15:02:03.407495   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-2rt9k" "namespace"="test-machine-watches-gclp7" "descendants"="Worker machines: machine-created-rlg7f" "indirect descendants count"=0
I0801 15:02:03.428436   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-2rt9k" "namespace"="test-machine-watches-gclp7" "count"=1
I0801 15:02:03.428513   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-2rt9k" "namespace"="test-machine-watches-gclp7" "descendants"="Worker machines: machine-created-rlg7f" "indirect descendants count"=0
I0801 15:02:04.187369   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-2rt9k" "machine"="machine-created-rlg7f" "namespace"="test-machine-watches-gclp7" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"d8cc2107-54c9-4eea-b496-9f5b8740839c","apiVersion":"v1"}
E0801 15:02:04.279932   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-rlg7f\" not found" "controller"="machine" "name"="machine-created-rlg7f" "namespace"="test-machine-watches-gclp7"
E0801 15:02:05.358279   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-cmmjf\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-hkfxn\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-hkfxn: secrets \"machine-reconcile-hkfxn-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-cmmjf" "namespace"="default"
I0801 15:02:06.359292   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-hkfxn" "machine"="machine-created-cmmjf" "namespace"="default" "cause"="noderef is nil" "node"=null
I0801 15:02:06.421081   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-hkfxn" "machine"="machine-created-cmmjf" "namespace"="default" "cause"="noderef is nil" "node"=null
I0801 15:02:06.463615   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-hkfxn" "machine"="machine-created-cmmjf" "namespace"="default" "cause"="noderef is nil" "node"=null
E0801 15:02:06.529134   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-cmmjf\" not found" "controller"="machine" "name"="machine-created-cmmjf" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.33s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.33s)
=== 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)
    --- PASS: TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one (0.00s)
    --- PASS: TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer (0.00s)
=== RUN   TestMachineOwnerReference
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0801 15:02:06.551912   10604 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0801 15:02:06.552049   10604 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
E0801 15:02:06.570074   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-hkfxn\" not found" "controller"="cluster" "name"="machine-reconcile-hkfxn" "namespace"="default"
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0801 15:02:06.576470   10604 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0801 15:02:06.576623   10604 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0801 15:02:06.580447   10604 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0801 15:02:06.580563   10604 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
... skipping 125 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
I0801 15:02:06.834910   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwh7l" "namespace"="test-mhc-wvzzt" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0801 15:02:06.854040   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0801 15:02:06.855183   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-zljnb\" not found"  "cluster"="test-mhc-wvzzt/test-cluster-zljnb"
E0801 15:02:06.863311   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-hwh7l\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-hwh7l\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-hwh7l" "namespace"="test-mhc-wvzzt"
=== 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
I0801 15:02:07.863594   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hwh7l" "namespace"="test-mhc-wvzzt" 
I0801 15:02:07.863706   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f57w9" "namespace"="test-mhc-tlvv9" 
I0801 15:02:07.863740   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hpmn" "namespace"="test-mhc-pbr6s" 
I0801 15:02:07.863777   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gscl2" "namespace"="test-mhc-wjstb" 
I0801 15:02:07.916919   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 15:02:07.986468   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gscl2" "namespace"="test-mhc-wjstb" 
I0801 15:02:07.997926   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gscl2" "namespace"="test-mhc-wjstb" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0801 15:02:08.026661   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fhnmq" "namespace"="test-mhc-t5pw8" 
E0801 15:02:08.051258   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-5lljz\" not found" "controller"="cluster" "name"="test-cluster-5lljz" "namespace"="test-mhc-wjstb"
I0801 15:02:08.124834   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0801 15:02:08.126424   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wjstb/test-cluster-5lljz"
I0801 15:02:08.166597   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fhnmq" "namespace"="test-mhc-t5pw8" 
I0801 15:02:08.184392   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fhnmq" "namespace"="test-mhc-t5pw8" 
E0801 15:02:08.232711   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-t5pw8/test-cluster-4l29q"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0801 15:02:08.238306   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fhnmq" "namespace"="test-mhc-t5pw8" 
I0801 15:02:08.358392   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
inframachine created: test-mhc-machine-infra-tr6gs
machine created: test-mhc-machine-9dvg2
I0801 15:02:08.387729   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 15:02:08.427133   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.427580   10604 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-lmh4k/test-mhc-wz8r7/test-mhc-machine-9dvg2/"
E0801 15:02:08.493347   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jxv6r, got []"  "node"="test-mhc-node-jxv6r"
node created: test-mhc-node-jxv6r
E0801 15:02:08.493738   10604 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-jxv6r"
I0801 15:02:08.494863   10604 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k" "noderef"="test-mhc-node-jxv6r"
E0801 15:02:08.514640   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jxv6r, got []"  "node"="test-mhc-node-jxv6r"
E0801 15:02:08.514692   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jxv6r, got []"  "node"="test-mhc-node-jxv6r"
E0801 15:02:08.516358   10604 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-jxv6r"
E0801 15:02:08.516397   10604 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-jxv6r"
inframachine created: test-mhc-machine-infra-tc57f
machine created: test-mhc-machine-4ffcl
I0801 15:02:08.593729   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.619186   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.620432   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.621492   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
... skipping 35 lines ...
I0801 15:02:08.720737   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.721805   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.724213   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.727132   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.728631   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.733593   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.733944   10604 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-lmh4k/test-mhc-wz8r7/test-mhc-machine-4ffcl/"
I0801 15:02:08.748247   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.748713   10604 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-lmh4k/test-mhc-wz8r7/test-mhc-machine-4ffcl/"
node created: test-mhc-node-vqcf2
E0801 15:02:08.755512   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vqcf2, got []"  "node"="test-mhc-node-vqcf2"
E0801 15:02:08.755910   10604 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-vqcf2"
I0801 15:02:08.765355   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.766507   10604 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k" "noderef"="test-mhc-node-vqcf2"
I0801 15:02:08.788893   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.799022   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
Cleaning up nodes, machines and infra machines.
I0801 15:02:08.811354   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.811810   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lmh4k/test-mhc-wz8r7/test-mhc-machine-9dvg2/"
I0801 15:02:08.842429   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.842977   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lmh4k/test-mhc-wz8r7/test-mhc-machine-9dvg2/"
I0801 15:02:08.843521   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lmh4k/test-mhc-wz8r7/test-mhc-machine-4ffcl/"
I0801 15:02:08.861092   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
I0801 15:02:08.861638   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lmh4k/test-mhc-wz8r7/test-mhc-machine-9dvg2/"
I0801 15:02:08.862138   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lmh4k/test-mhc-wz8r7/test-mhc-machine-4ffcl/"
E0801 15:02:08.867287   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lmh4k/test-cluster-pxxt4"
I0801 15:02:08.871912   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wz8r7" "namespace"="test-mhc-lmh4k" 
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0801 15:02:08.925556   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:08.995933   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
inframachine created: test-mhc-machine-infra-kld8k
machine created: test-mhc-machine-qrj2p
I0801 15:02:09.022108   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0801 15:02:09.122917   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-gclp7/machine-reconcile-2rt9k"
I0801 15:02:09.147979   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.148758   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.149377   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.150511   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.152332   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.154129   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 362 lines ...
I0801 15:02:09.915398   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.917397   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.919133   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.921189   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.922949   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.924674   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
E0801 15:02:09.925886   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:09.926382   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.928100   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.929986   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.941039   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.943454   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:09.945553   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 382 lines ...
I0801 15:02:10.905888   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.914078   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.916262   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.918697   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.921353   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.930838   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
E0801 15:02:10.932208   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:10.942394   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.944273   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.945990   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.947701   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.949412   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:10.951781   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 364 lines ...
I0801 15:02:11.945662   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:11.947411   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:11.948050   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:11.949145   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:11.950946   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:11.952853   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:11.953487   10604 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-5bwtc/test-mhc-p66jc/test-mhc-machine-qrj2p/"
E0801 15:02:11.953714   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:11.973012   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:11.973249   10604 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-5bwtc/test-mhc-p66jc/test-mhc-machine-qrj2p/"
node created: test-mhc-node-9966r
E0801 15:02:12.053733   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9966r, got []"  "node"="test-mhc-node-9966r"
I0801 15:02:12.063140   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
inframachine created: test-mhc-machine-infra-nf4k4
machine created: test-mhc-machine-dmqz9
I0801 15:02:12.104589   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.138200   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.146724   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 223 lines ...
I0801 15:02:12.927126   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.930241   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.943448   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.947597   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.950458   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.953413   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
E0801 15:02:12.956197   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:12.958040   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.962888   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.972342   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.976051   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.979799   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:12.983509   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 283 lines ...
I0801 15:02:14.006437   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.009563   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.012318   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.016081   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.017484   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.020915   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
E0801 15:02:14.022896   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:14.023138   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.024512   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.025729   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.039776   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.042887   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:14.045374   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 225 lines ...
I0801 15:02:14.999625   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.005477   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.008265   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.013168   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.017737   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.037266   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
E0801 15:02:15.044295   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:15.044884   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.045785   10604 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-5bwtc/test-mhc-p66jc/test-mhc-machine-dmqz9/"
I0801 15:02:15.064389   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.064827   10604 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-5bwtc/test-mhc-p66jc/test-mhc-machine-dmqz9/"
E0801 15:02:15.145517   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wg89j, got []"  "node"="test-mhc-node-wg89j"
node created: test-mhc-node-wg89j
I0801 15:02:15.155955   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
inframachine created: test-mhc-machine-infra-gx8lw
machine created: test-mhc-machine-79cnt
I0801 15:02:15.190795   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:15.209644   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 177 lines ...
I0801 15:02:16.013339   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.016896   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.024619   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.030287   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.033223   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.055770   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
E0801 15:02:16.062649   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:16.063257   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.078101   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.085428   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.097458   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.121464   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:16.129469   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 202 lines ...
I0801 15:02:17.097522   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.101453   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.123904   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.127071   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.133058   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.154720   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
E0801 15:02:17.159602   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:17.163202   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.167273   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.170661   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.173004   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.175837   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:17.182972   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
... skipping 195 lines ...
I0801 15:02:18.157641   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.161386   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.165770   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.172699   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.175583   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.182208   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.183545   10604 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-5bwtc/test-mhc-p66jc/test-mhc-machine-79cnt/"
E0801 15:02:18.185399   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:18.199380   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.200369   10604 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-5bwtc/test-mhc-p66jc/test-mhc-machine-79cnt/"
node created: test-mhc-node-qwmk6
E0801 15:02:18.207033   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qwmk6, got []"  "node"="test-mhc-node-qwmk6"
I0801 15:02:18.218498   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.219764   10604 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-5bwtc/test-mhc-p66jc/test-mhc-machine-79cnt/test-mhc-node-qwmk6"
Cleaning up nodes, machines and infra machines.
I0801 15:02:18.261110   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.262093   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5bwtc/test-mhc-p66jc/test-mhc-machine-79cnt/"
Cleaning up nodes, machines and infra machines.
I0801 15:02:18.303036   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:18.303682   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5bwtc/test-mhc-p66jc/test-mhc-machine-qrj2p/"
I0801 15:02:18.343167   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-tfdcc" "namespace"="test-mhc-5bwtc" "count"=2
I0801 15:02:18.343243   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tfdcc" "namespace"="test-mhc-5bwtc" "descendants"="Worker machines: test-mhc-machine-qrj2p,test-mhc-machine-dmqz9,test-mhc-machine-79cnt" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0801 15:02:18.352222   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-tfdcc" "namespace"="test-mhc-5bwtc" "count"=2
I0801 15:02:18.352319   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tfdcc" "namespace"="test-mhc-5bwtc" "descendants"="Worker machines: test-mhc-machine-qrj2p,test-mhc-machine-dmqz9,test-mhc-machine-79cnt" "indirect descendants count"=1
inframachine created: test-mhc-machine-infra-72xgb
machine created: test-mhc-machine-8z887
I0801 15:02:18.497848   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5bwtc/test-mhc-p66jc/test-mhc-machine-79cnt/"
E0801 15:02:18.507010   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-p66jc\" not found" "controller"="machinehealthcheck" "name"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc"
I0801 15:02:19.190552   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tfdcc" "machine"="test-mhc-machine-dmqz9" "namespace"="test-mhc-5bwtc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wg89j"}
E0801 15:02:19.268037   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dmqz9\" not found" "controller"="machine" "name"="test-mhc-machine-dmqz9" "namespace"="test-mhc-5bwtc"
I0801 15:02:19.507469   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:19.547081   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 15:02:19.576406   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p66jc" "namespace"="test-mhc-5bwtc" 
I0801 15:02:19.576472   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:19.581472   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:19.603173   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:19.646691   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:19.727801   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:19.893482   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:20.214624   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:20.270449   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:20.855699   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:21.271017   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tfdcc" "machine"="test-mhc-machine-79cnt" "namespace"="test-mhc-5bwtc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-qwmk6"}
E0801 15:02:21.328272   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-79cnt\" not found" "controller"="machine" "name"="test-mhc-machine-79cnt" "namespace"="test-mhc-5bwtc"
I0801 15:02:22.137007   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:22.328721   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:23.329402   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tfdcc" "machine"="test-mhc-machine-qrj2p" "namespace"="test-mhc-5bwtc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9966r"}
I0801 15:02:23.352399   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-tfdcc" "namespace"="test-mhc-5bwtc" "count"=1
I0801 15:02:23.352498   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tfdcc" "namespace"="test-mhc-5bwtc" "descendants"="Worker machines: test-mhc-machine-qrj2p" "indirect descendants count"=0
E0801 15:02:23.389209   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qrj2p\" not found" "controller"="machine" "name"="test-mhc-machine-qrj2p" "namespace"="test-mhc-5bwtc"
I0801 15:02:24.412676   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.419021   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:24.421214   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
E0801 15:02:24.462168   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jvb7j, got []"  "node"="test-mhc-node-jvb7j"
node created: test-mhc-node-jvb7j
E0801 15:02:24.462362   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jvb7j, got []"  "node"="test-mhc-node-jvb7j"
I0801 15:02:24.462707   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.481739   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
inframachine created: test-mhc-machine-infra-xfcf8
machine created: test-mhc-machine-q2jrq
I0801 15:02:24.530460   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.551445   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.556538   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.578408   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.619926   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.701549   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:24.863216   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:25.184790   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:25.421665   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:25.826356   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.435237   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.438284   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.439456   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.447034   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.457678   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.468009   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.476620   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:26.484160   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:26.485470   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.513510   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:26.521253   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v7428, got []"  "node"="test-mhc-node-v7428"
node created: test-mhc-node-v7428
E0801 15:02:26.521541   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v7428, got []"  "node"="test-mhc-node-v7428"
I0801 15:02:26.535179   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
inframachine created: test-mhc-machine-infra-zbpp7
machine created: test-mhc-machine-l6bh4
I0801 15:02:26.555745   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.568122   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:26.582995   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:27.107816   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:27.484690   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
E0801 15:02:28.367997   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5bwtc/test-cluster-tfdcc"
I0801 15:02:28.496283   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:28.533147   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:28.547719   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:28.566032   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:28.583028   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:28.599098   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:28.604246   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:28.604332   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:28.631135   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
E0801 15:02:28.672231   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5shss, got []"  "node"="test-mhc-node-5shss"
node created: test-mhc-node-5shss
Cleaning up nodes, machines and infra machines.
I0801 15:02:28.689920   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:28.708212   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
Cleaning up nodes, machines and infra machines.
I0801 15:02:28.750227   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4pq25" "namespace"="test-mhc-7cwmn" "count"=2
... skipping 4 lines ...
inframachine created: test-mhc-machine-infra-sjsbd
machine created: test-mhc-machine-58hxh
I0801 15:02:28.951107   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:29.001153   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 15:02:29.122984   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c6prt" "namespace"="test-mhc-7cwmn" 
I0801 15:02:29.123052   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
E0801 15:02:29.604665   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:30.605208   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4pq25" "machine"="test-mhc-machine-8z887" "namespace"="test-mhc-7cwmn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jvb7j"}
E0801 15:02:30.658750   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8z887\" not found" "controller"="machine" "name"="test-mhc-machine-8z887" "namespace"="test-mhc-7cwmn"
I0801 15:02:31.659328   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4pq25" "machine"="test-mhc-machine-q2jrq" "namespace"="test-mhc-7cwmn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-v7428"}
E0801 15:02:31.714599   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-q2jrq\" not found" "controller"="machine" "name"="test-mhc-machine-q2jrq" "namespace"="test-mhc-7cwmn"
I0801 15:02:32.715333   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4pq25" "machine"="test-mhc-machine-l6bh4" "namespace"="test-mhc-7cwmn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5shss"}
E0801 15:02:32.763456   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l6bh4\" not found" "controller"="machine" "name"="test-mhc-machine-l6bh4" "namespace"="test-mhc-7cwmn"
E0801 15:02:33.769961   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7cwmn/test-cluster-4pq25"
I0801 15:02:33.771707   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:33.775275   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
E0801 15:02:33.775315   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
E0801 15:02:33.838713   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m8nf7, got []"  "node"="test-mhc-node-m8nf7"
node created: test-mhc-node-m8nf7
I0801 15:02:33.849010   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
inframachine created: test-mhc-machine-infra-8rmvt
machine created: test-mhc-machine-9hlks
I0801 15:02:33.877435   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:33.883557   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
E0801 15:02:34.775732   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:35.790928   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:35.802832   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:35.831035   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:35.836930   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:35.847717   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:35.853182   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:35.867945   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
node created: test-mhc-node-8l9rz
E0801 15:02:35.881791   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8l9rz, got []"  "node"="test-mhc-node-8l9rz"
I0801 15:02:35.882026   10604 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-9hlks" "namespace"="test-mhc-6rj6b" "noderef"="test-mhc-node-8l9rz"
I0801 15:02:35.890364   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
inframachine created: test-mhc-machine-infra-zpg25
I0801 15:02:35.922008   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:35.930792   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
machine created: test-mhc-machine-pddnh
... skipping 4 lines ...
I0801 15:02:36.002062   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:36.023710   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
Cleaning up nodes, machines and infra machines.
I0801 15:02:36.039275   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
Cleaning up nodes, machines and infra machines.
I0801 15:02:36.057720   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:36.058373   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6rj6b/test-mhc-5fs5p/test-mhc-machine-58hxh/"
I0801 15:02:36.091475   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:36.092315   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6rj6b/test-mhc-5fs5p/test-mhc-machine-58hxh/"
I0801 15:02:36.093048   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6rj6b/test-mhc-5fs5p/test-mhc-machine-9hlks/"
I0801 15:02:36.129560   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-n22nm" "namespace"="test-mhc-6rj6b" "count"=3
I0801 15:02:36.129649   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n22nm" "namespace"="test-mhc-6rj6b" "descendants"="Worker machines: test-mhc-machine-58hxh,test-mhc-machine-9hlks,test-mhc-machine-pddnh" "indirect descendants count"=0
I0801 15:02:36.134123   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-n22nm" "namespace"="test-mhc-6rj6b" "count"=3
I0801 15:02:36.134199   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n22nm" "namespace"="test-mhc-6rj6b" "descendants"="Worker machines: test-mhc-machine-58hxh,test-mhc-machine-9hlks,test-mhc-machine-pddnh" "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-dc5sh
machine created: test-mhc-machine-99ltc
E0801 15:02:36.273592   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-5fs5p\" not found" "controller"="machinehealthcheck" "name"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b"
E0801 15:02:36.293591   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-9hlks\" in namespace \"test-mhc-6rj6b\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-9hlks" "namespace"="test-mhc-6rj6b"
I0801 15:02:37.274438   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.299735   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n22nm" "machine"="test-mhc-machine-58hxh" "namespace"="test-mhc-6rj6b" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-m8nf7"}
I0801 15:02:37.299981   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 15:02:37.335151   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5fs5p" "namespace"="test-mhc-6rj6b" 
I0801 15:02:37.335345   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.346489   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
... skipping 6 lines ...
I0801 15:02:37.372411   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.374452   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.376730   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.378931   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.380807   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.382712   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
E0801 15:02:37.382832   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-58hxh\" not found" "controller"="machine" "name"="test-mhc-machine-58hxh" "namespace"="test-mhc-6rj6b"
I0801 15:02:37.384627   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.387368   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.389754   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.391953   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.394348   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:37.396467   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
... skipping 375 lines ...
I0801 15:02:38.426033   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.428139   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.430135   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.432052   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.434423   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.436401   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
E0801 15:02:38.436539   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-pddnh\" not found" "controller"="machine" "name"="test-mhc-machine-pddnh" "namespace"="test-mhc-6rj6b"
I0801 15:02:38.438094   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.444041   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.446075   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.448070   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.450488   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:38.452618   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
... skipping 426 lines ...
I0801 15:02:39.454078   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.455428   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.457401   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.459436   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.462135   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n22nm" "machine"="test-mhc-machine-9hlks" "namespace"="test-mhc-6rj6b" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-8l9rz","uid":"aa3c45d2-b9c1-4806-8f9a-5ad16c515920","apiVersion":"v1"}
I0801 15:02:39.464040   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.464339   10604 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-lgk8h/test-mhc-s66qr/test-mhc-machine-99ltc/"
I0801 15:02:39.481545   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.481915   10604 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-lgk8h/test-mhc-s66qr/test-mhc-machine-99ltc/"
node created: test-mhc-node-894qd
E0801 15:02:39.501790   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-894qd, got []"  "node"="test-mhc-node-894qd"
E0801 15:02:39.501791   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-894qd, got []"  "node"="test-mhc-node-894qd"
I0801 15:02:39.509342   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
E0801 15:02:39.518709   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9hlks\" not found" "controller"="machine" "name"="test-mhc-machine-9hlks" "namespace"="test-mhc-6rj6b"
I0801 15:02:39.524674   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.525694   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.535045   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.535370   10604 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-lgk8h/test-mhc-s66qr/test-mhc-machine-99ltc/test-mhc-node-894qd"
I0801 15:02:39.570843   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.571340   10604 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-lgk8h/test-mhc-s66qr/test-mhc-machine-99ltc/test-mhc-node-894qd"
Cleaning up nodes, machines and infra machines.
I0801 15:02:39.580273   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.580668   10604 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgk8h/test-mhc-s66qr/test-mhc-machine-99ltc/"
I0801 15:02:39.600809   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-97t4d" "namespace"="test-mhc-lgk8h" "descendants"="Worker machines: test-mhc-machine-99ltc" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0801 15:02:39.606715   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-97t4d" "namespace"="test-mhc-lgk8h" "descendants"="Worker machines: test-mhc-machine-99ltc" "indirect descendants count"=1
I0801 15:02:39.712461   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" "creating"=1 "need"=1
I0801 15:02:39.712597   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:39.725685   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-6v259-h5t8g\"" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:39.725946   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s66qr" "namespace"="test-mhc-lgk8h" 
I0801 15:02:39.806880   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:39.841489   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 15:02:39.841577   10604 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:39.870672   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
E0801 15:02:40.519178   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
I0801 15:02:40.870900   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
E0801 15:02:41.148150   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6rj6b/test-cluster-n22nm"
E0801 15:02:41.519742   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:41.872190   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:42.520322   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-97t4d" "machine"="test-mhc-machine-99ltc" "namespace"="test-mhc-lgk8h" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-894qd"}
E0801 15:02:42.577555   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-99ltc\" not found" "controller"="machine" "name"="test-mhc-machine-99ltc" "namespace"="test-mhc-lgk8h"
I0801 15:02:42.873848   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.587876   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.588570   10604 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.601803   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.603109   10604 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.632593   10604 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
... skipping 4 lines ...
I0801 15:02:43.690385   10604 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.696087   10604 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.696141   10604 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.719279   10604 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.719340   10604 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:43.875304   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
E0801 15:02:44.622890   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lgk8h/test-cluster-97t4d"
I0801 15:02:44.699857   10604 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:44.699918   10604 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.000748   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.001279   10604 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-m2fpg/test-mhc-ftp6t/mhc-ms-6v259-h5t8g/"
I0801 15:02:45.011777   10604 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.022152   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.022626   10604 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-m2fpg/test-mhc-ftp6t/mhc-ms-6v259-h5t8g/"
I0801 15:02:45.023602   10604 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.023653   10604 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.035458   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.035812   10604 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-m2fpg/test-mhc-ftp6t/mhc-ms-6v259-h5t8g/"
I0801 15:02:45.036037   10604 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.053234   10604 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.053446   10604 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.078798   10604 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-k8lm8" "namespace"="test-mhc-m2fpg" "count"=1
I0801 15:02:45.078865   10604 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-k8lm8" "namespace"="test-mhc-m2fpg" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-6v259"
I0801 15:02:45.079960   10604 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" "machine"="mhc-ms-6v259-h5t8g"
I0801 15:02:45.087679   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k8lm8" "namespace"="test-mhc-m2fpg" "descendants"="Machine sets: mhc-ms-6v259;Worker machines: mhc-ms-6v259-h5t8g" "indirect descendants count"=1
I0801 15:02:45.093166   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.093676   10604 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-m2fpg/test-mhc-ftp6t/mhc-ms-6v259-h5t8g/"
I0801 15:02:45.095999   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k8lm8" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" "cause"="cluster is being deleted" "node"=null
I0801 15:02:45.099945   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ftp6t" "namespace"="test-mhc-m2fpg" 
I0801 15:02:45.100821   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k8lm8" "namespace"="test-mhc-m2fpg" "descendants"="Worker machines: mhc-ms-6v259-h5t8g" "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
E0801 15:02:45.127434   10604 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-6v259\" not found" "machineset"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg" 
E0801 15:02:45.127657   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-6v259\" not found" "controller"="machineset" "name"="mhc-ms-6v259" "namespace"="test-mhc-m2fpg"
I0801 15:02:45.164336   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k8lm8" "machine"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg" "cause"="cluster is being deleted" "node"=null
E0801 15:02:45.216414   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-6v259-h5t8g\" not found" "controller"="machine" "name"="mhc-ms-6v259-h5t8g" "namespace"="test-mhc-m2fpg"
I0801 15:02:45.331450   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
inframachine created: test-mhc-machine-infra-gttnv
I0801 15:02:45.352988   10604 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-zxkpb
I0801 15:02:45.498486   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:45.516233   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
... skipping 237 lines ...
I0801 15:02:46.225597   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.227905   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.228922   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.231311   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.233982   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.235685   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
E0801 15:02:46.237480   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
E0801 15:02:46.284368   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-x99fq, got []"  "node"="test-mhc-node-x99fq"
E0801 15:02:46.284368   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-x99fq, got []"  "node"="test-mhc-node-x99fq"
node created: test-mhc-node-x99fq
I0801 15:02:46.365691   10604 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-zxkpb" "target"="test-mhc-cdwf5/test-mhc-m54hh/test-mhc-machine-zxkpb/"
I0801 15:02:46.384856   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.452949   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.473944   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.488113   10604 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-zxkpb" "target"="test-mhc-cdwf5/test-mhc-m54hh/test-mhc-machine-zxkpb/test-mhc-node-x99fq"
I0801 15:02:46.508287   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
Cleaning up nodes, machines and infra machines.
I0801 15:02:46.518526   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.522890   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.525647   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
I0801 15:02:46.529342   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m54hh" "namespace"="test-mhc-cdwf5" 
... skipping 225 lines ...
I0801 15:02:47.306480   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.308657   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.315791   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.320449   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.322525   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.324322   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
E0801 15:02:47.325506   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zxkpb\" not found" "controller"="machine" "name"="test-mhc-machine-zxkpb" "namespace"="test-mhc-cdwf5"
I0801 15:02:47.326209   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.328349   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.331215   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.333783   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.335937   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:47.337919   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
... skipping 356 lines ...
I0801 15:02:48.345616   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.348386   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.349889   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.350999   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.352169   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.354011   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
E0801 15:02:48.356030   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
I0801 15:02:48.363593   10604 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-6q2lr" "target"="test-mhc-c7gh6/test-mhc-4wtdz/test-mhc-machine-6q2lr/"
I0801 15:02:48.389614   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
E0801 15:02:48.449428   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xgsgn, got []"  "node"="test-mhc-node-xgsgn"
E0801 15:02:48.450241   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xgsgn, got []"  "node"="test-mhc-node-xgsgn"
E0801 15:02:48.450916   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xgsgn, got []"  "node"="test-mhc-node-xgsgn"
node created: test-mhc-node-xgsgn
I0801 15:02:48.484575   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.537712   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.554750   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.571635   10604 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-6q2lr" "target"="test-mhc-c7gh6/test-mhc-4wtdz/test-mhc-machine-6q2lr/test-mhc-node-xgsgn"
I0801 15:02:48.619484   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.638012   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.687074   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
Cleaning up nodes, machines and infra machines.
I0801 15:02:48.701882   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.711949   10604 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-6q2lr" "target"="test-mhc-c7gh6/test-mhc-4wtdz/test-mhc-machine-6q2lr/"
I0801 15:02:48.745736   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tzrww" "namespace"="test-mhc-c7gh6" "descendants"="Worker machines: test-mhc-machine-6q2lr" "indirect descendants count"=1
I0801 15:02:48.761232   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
I0801 15:02:48.762252   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tzrww" "namespace"="test-mhc-c7gh6" "descendants"="Worker machines: test-mhc-machine-6q2lr" "indirect descendants count"=1
I0801 15:02:48.775062   10604 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtdz" "namespace"="test-mhc-c7gh6" 
--- PASS: TestMachineHealthCheck_Reconcile (41.98s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
... skipping 14 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.44s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.22s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0801 15:02:48.779888   10604 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
E0801 15:02:48.782508   10604 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
E0801 15:02:48.786977   10604 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0801 15:02:48.787324   10604 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
E0801 15:02:48.787949   10604 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0801 15:02:48.792759   10604 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0801 15:02:48.794092   10604 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0801 15:02:48.797063   10604 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
E0801 15:02:48.815403   10604 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
E0801 15:02:48.818217   10604 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 66 lines ...
I0801 15:02:49.026716   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-4jj2g" "namespace"="ms-test" 
I0801 15:02:49.069060   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-4jj2g-h5rxb\"" "machineset"="ms-4jj2g" "namespace"="ms-test" 
I0801 15:02:49.294914   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-4jj2g" "namespace"="ms-test" "creating"=1 "need"=2
I0801 15:02:49.295009   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-4jj2g" "namespace"="ms-test" 
I0801 15:02:49.323929   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-4jj2g-k7w4h\"" "machineset"="ms-4jj2g" "namespace"="ms-test" 
I0801 15:02:49.357510   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tzrww" "machine"="test-mhc-machine-6q2lr" "namespace"="test-mhc-c7gh6" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xgsgn"}
E0801 15:02:49.452535   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.452788   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.452865   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.459561   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6q2lr\" not found" "controller"="machine" "name"="test-mhc-machine-6q2lr" "namespace"="test-mhc-c7gh6"
E0801 15:02:49.559849   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.559874   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.559931   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.559874   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.559937   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.559985   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-k7w4h-4g9s7, got []"  "node"="ms-4jj2g-k7w4h-4g9s7"
E0801 15:02:49.628232   10604 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-4jj2g-k7w4h-4g9s7 for machine ms-test/ms-4jj2g-k7w4h: the cache is not started, can not read objects" "machineset"="ms-4jj2g" "namespace"="ms-test" 
E0801 15:02:49.633520   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.633782   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.634213   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.738633   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.738680   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.738772   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.738837   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.738970   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
E0801 15:02:49.739037   10604 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-4jj2g-h5rxb-wldbt, got []"  "node"="ms-4jj2g-h5rxb-wldbt"
I0801 15:02:49.891550   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-4jj2g-k7w4h,ms-4jj2g-h5rxb" "indirect descendants count"=2
I0801 15:02:49.898816   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-4jj2g-k7w4h,ms-4jj2g-h5rxb" "indirect descendants count"=2
••E0801 15:02:50.044421   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-m4hb7\" not found" "controller"="cluster" "name"="test1-m4hb7" "namespace"="default"
E0801 15:02:51.082201   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-m2fpg/test-cluster-k8lm8"
•I0801 15:02:51.176564   10604 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jkz4n" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0801 15:02:51.299592   10604 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jkz4n" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0801 15:02:51.306153   10604 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-jkz4n" "namespace"="default"
E0801 15:02:52.324841   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jkz4n: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jkz4n" "namespace"="default"
•E0801 15:02:53.338212   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-cdwf5/test-cluster-sv5bx"
E0801 15:02:53.356553   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-hpxh8\" not found" "controller"="cluster" "name"="test3-hpxh8" "namespace"="default"
E0801 15:02:54.357250   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jkz4n: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jkz4n" "namespace"="default"
E0801 15:02:55.406051   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-c7gh6/test-cluster-tzrww"
E0801 15:02:55.406693   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jkz4n: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jkz4n" "namespace"="default"
•I0801 15:02:56.407378   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-4jj2g-k7w4h,ms-4jj2g-h5rxb" "indirect descendants count"=2
E0801 15:02:56.412308   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6dxjk: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6dxjk" "namespace"="default"
E0801 15:02:56.477824   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-9dvg2\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-9dvg2" "namespace"="test-mhc-lmh4k"
E0801 15:02:57.413112   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jkz4n: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jkz4n" "namespace"="default"
E0801 15:02:58.423535   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6dxjk: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6dxjk" "namespace"="default"
•E0801 15:02:58.596493   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-pxxt4\" for machine \"test-mhc-machine-4ffcl\" in namespace \"test-mhc-lmh4k\": Cluster.cluster.x-k8s.io \"test-cluster-pxxt4\" not found" "controller"="machine" "name"="test-mhc-machine-4ffcl" "namespace"="test-mhc-lmh4k"
E0801 15:02:59.424187   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jkz4n: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jkz4n" "namespace"="default"
E0801 15:03:00.424916   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6dxjk: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6dxjk" "namespace"="default"
E0801 15:03:01.437471   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jkz4n: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jkz4n" "namespace"="default"
I0801 15:03:01.564467   10604 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-f6277" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0801 15:03:01.579701   10604 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-f6277" "namespace"="default" 
E0801 15:03:01.605617   10604 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-f6277" "namespace"="default"
E0801 15:03:02.438679   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6dxjk: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6dxjk" "namespace"="default"
I0801 15:03:02.625587   10604 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-f6277" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0801 15:03:02.625813   10604 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-f6277" "namespace"="default" "noderef"="id-node-1"
E0801 15:03:02.643956   10604 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-f6277" "namespace"="default"
I0801 15:03:03.439524   10604 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-4jj2g-k7w4h,ms-4jj2g-h5rxb" "indirect descendants count"=2
E0801 15:03:03.444285   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jkz4n: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jkz4n" "namespace"="default"
•I0801 15:03:03.522318   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0801 15:03:03.522379   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.537531   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-nfw9j-6657c7fddb-7hfv8\"" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.537583   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.548875   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-nfw9j-6657c7fddb-zpxrq\"" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.606191   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0801 15:03:03.606230   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.618035   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-nfw9j-6657c7fddb-7z794\"" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.618107   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.628708   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-nfw9j-6657c7fddb-hdr6g\"" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.644655   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-2fzcj" "machine"="test6-f6277" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"1f1d06ca-8a2e-4dba-bf98-d634aaaac56f","apiVersion":"v1"}
E0801 15:03:03.667868   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-f6277\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-f6277" "namespace"="default"
I0801 15:03:03.718446   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0801 15:03:03.718507   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.733545   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nfw9j-6657c7fddb-8kgjw\"" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" 
I0801 15:03:03.828580   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0801 15:03:03.828745   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
I0801 15:03:03.843356   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nfw9j-cdfc6fd6c-npbc9\"" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
E0801 15:03:03.957887   10604 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-nfw9j-cdfc6fd6c-npbc9-7cvb5 for machine md-test/md-nfw9j-cdfc6fd6c-npbc9: the cache is not started, can not read objects" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
I0801 15:03:03.991879   10604 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0801 15:03:03.991915   10604 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0801 15:03:03.997201   10604 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "machine"="md-nfw9j-6657c7fddb-7z794"
I0801 15:03:04.016852   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0801 15:03:04.016936   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
I0801 15:03:04.027937   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nfw9j-cdfc6fd6c-kz845\"" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
I0801 15:03:04.202905   10604 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0801 15:03:04.202957   10604 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0801 15:03:04.213595   10604 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "machine"="md-nfw9j-6657c7fddb-hdr6g"
I0801 15:03:04.323335   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0801 15:03:04.323389   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
I0801 15:03:04.334204   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nfw9j-cdfc6fd6c-wnph7\"" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
E0801 15:03:04.445082   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6dxjk: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6dxjk" "namespace"="default"
I0801 15:03:04.582421   10604 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0801 15:03:04.582485   10604 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0801 15:03:04.589237   10604 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nfw9j-6657c7fddb" "namespace"="md-test" "machine"="md-nfw9j-6657c7fddb-8kgjw"
I0801 15:03:04.711125   10604 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-2fzcj" "machine"="test6-f6277" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"1f1d06ca-8a2e-4dba-bf98-d634aaaac56f","apiVersion":"v1"}
E0801 15:03:04.711741   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-f6277\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-f6277" "namespace"="default"
I0801 15:03:04.723958   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0801 15:03:04.724027   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-nfw9j-74d45c49c5" "namespace"="md-test" 
I0801 15:03:04.741717   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nfw9j-74d45c49c5-62b4b\"" "machineset"="md-nfw9j-74d45c49c5" "namespace"="md-test" 
I0801 15:03:04.969984   10604 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0801 15:03:04.970035   10604 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0801 15:03:04.975317   10604 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "machine"="md-nfw9j-cdfc6fd6c-npbc9"
... skipping 6 lines ...
I0801 15:03:05.134460   10604 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nfw9j-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0801 15:03:05.134495   10604 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nfw9j-74d45c49c5" "namespace"="md-test" 
I0801 15:03:05.145382   10604 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nfw9j-74d45c49c5-2lnkb\"" "machineset"="md-nfw9j-74d45c49c5" "namespace"="md-test" 
I0801 15:03:05.282566   10604 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0801 15:03:05.282610   10604 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0801 15:03:05.288910   10604 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" "machine"="md-nfw9j-cdfc6fd6c-wnph7"
E0801 15:03:05.377033   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
•I0801 15:03:05.380472   10604 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"
I0801 15:03:05.381348   10604 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0801 15:03:05.381398   10604 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"
I0801 15:03:05.382086   10604 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0801 15:03:05.382119   10604 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0801 15:03:05.382649   10604 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
... skipping 13 lines ...
I0801 15:03:05.397357   10604 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"
•I0801 15:03:05.399634   10604 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"
I0801 15:03:05.400722   10604 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"
I0801 15:03:05.401872   10604 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0801 15:03:05.401919   10604 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0801 15:03:05.402778   10604 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0801 15:03:05.404685   10604 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" 
•

Ran 16 of 16 Specs in 16.583 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.58s)
PASS
Tearing down test suite
E0801 15:03:05.406359   10604 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-nfw9j-cdfc6fd6c-wnph7-2vwnm for machine md-test/md-nfw9j-cdfc6fd6c-wnph7: the cache is not started, can not read objects" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
E0801 15:03:05.406457   10604 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 15:03:05.406509   10604 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-454312856/tls.crt: no such file or directory"  
E0801 15:03:05.406523   10604 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0801 15:03:05.406539   10604 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0801 15:03:05.406606   10604 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0801 15:03:05.406639   10604 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0801 15:03:05.406666   10604 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0801 15:03:05.406686   10604 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0801 15:03:05.406796   10604 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0801 15:03:05.406895   10604 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0801 15:03:05.406544   10604 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-454312856/tls.crt: no such file or directory"  
E0801 15:03:05.406987   10604 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster\" not found"  "cluster"="md-test/test-cluster"
E0801 15:03:05.407083   10604 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: Patch http://127.0.0.1:36811/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-nfw9j-cdfc6fd6c/status: dial tcp 127.0.0.1:36811: connect: connection refused" "machineset"="md-nfw9j-cdfc6fd6c" "namespace"="md-test" 
E0801 15:03:05.408418   10604 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: Patch http://127.0.0.1:36811/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-nfw9j-cdfc6fd6c/status: dial tcp 127.0.0.1:36811: connect: connection refused" "controller"="machineset" "name"="md-nfw9j-cdfc6fd6c" "namespace"="md-test"
E0801 15:03:05.407203   10604 reflector.go:153] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to list *v1.Node: Get http://127.0.0.1:36811/api/v1/nodes?limit=500&resourceVersion=0&timeout=10s: dial tcp 127.0.0.1:36811: connect: connection refused
E0801 15:03:05.409244   10604 event.go:272] Unable to write event: 'Post http://127.0.0.1:36811/api/v1/namespaces/md-test/events: dial tcp 127.0.0.1:36811: connect: connection refused' (may retry after sleeping)
E0801 15:03:05.439329   10604 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:36811/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1256&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:36811: connect: connection refused
E0801 15:03:05.439500   10604 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:36811/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1256&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:36811: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	78.862s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0801 15:02:02.495809   11034 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0801 15:02:02.515186   11034 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0801 15:02:02.716393   11034 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0801 15:02:02.716460   11034 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0801 15:02:02.716725   11034 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0801 15:02:03.246736   11034 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0801 15:02:05.283211   11034 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-8v4lq/test-cluster"
•E0801 15:02:05.782453   11034 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-ms56k/test-cluster"
•E0801 15:02:06.354594   11034 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:46045/?timeout=50ms: dial tcp 127.0.0.1:46045: connect: connection refused"  "cluster"="cluster-cache-test-rq8dd/test-cluster"
•I0801 15:02:06.573179   11034 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0801 15:02:06.574291   11034 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0801 15:02:06.574345   11034 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-169408424/tls.crt: no such file or directory"  
E0801 15:02:06.629406   11034 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:46781/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:46781: connect: connection refused


Ran 5 of 5 Specs in 18.168 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (18.17s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	18.400s
?   	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
I0801 15:02:18.111951   11696 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
E0801 15:02:18.114111   11696 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
I0801 15:02:18.115269   11696 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0801 15:02:18.115629   11696 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
I0801 15:02:33.578988   11696 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
I0801 15:02:33.579058   11696 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: 1659366122
Will run 1 of 1 specs

E0801 15:02:33.602414   11696 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-xdthlv\" not found" "kubeadmControlPlane"="kcp-foo-xdthlv" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.021 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0801 15:02:33.604054   11696 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-9ctm3f" "kubeadmControlPlane"="kcp-foo-9ctm3f" "namespace"="test" 
I0801 15:02:35.547108   11696 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-9ctm3f" "kubeadmControlPlane"="kcp-foo-9ctm3f" "namespace"="test" "needRollout"=["kcp-foo-9ctm3f-7v9nm"]
I0801 15:02:35.547283   11696 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-9ctm3f" "kubeadmControlPlane"="kcp-foo-9ctm3f" "namespace"="test" "failures"="[machine kcp-foo-9ctm3f-6rcjc does not have APIServerPodHealthy condition, machine kcp-foo-9ctm3f-6rcjc does not have ControllerManagerPodHealthy condition, machine kcp-foo-9ctm3f-6rcjc does not have SchedulerPodHealthy condition, machine kcp-foo-9ctm3f-6rcjc does not have EtcdPodHealthy condition, machine kcp-foo-9ctm3f-6rcjc does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.95s)
... skipping 60 lines ...
==================================
Random Seed: 1659366121
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1659366121
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.02s)
=== 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
E0801 15:02:18.741439   11651 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"  
E0801 15:02:27.064855   11651 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"  
E0801 15:02:36.050907   11651 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"  
E0801 15:02:47.181241   11651 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"  
E0801 15:03:03.654495   11651 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"  
E0801 15:03:16.663063   11651 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"  
E0801 15:03:34.310498   11651 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"  
E0801 15:03:55.234235   11651 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"  
E0801 15:04:26.250791   11651 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"  
E0801 15:05:11.408273   11651 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 383 lines ...
I0801 15:02:27.597170   11950 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0801 15:02:27.604152   11950 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0801 15:02:27.704610   11950 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0801 15:02:27.805166   11950 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0801 15:02:27.805295   11950 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0801 15:02:27.901672   11950 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-uj0hsf"} 
•E0801 15:02:27.944841   11950 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"
I0801 15:02:29.008526   11950 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-s9s1ei"} 
E0801 15:02:29.052957   11950 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"
•E0801 15:02:40.136981   11950 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"

------------------------------
• Failure [11.086 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0801 15:02:41.320417   11950 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"
•E0801 15:02:42.374126   11950 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"
•I0801 15:02:43.422855   11950 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0801 15:02:43.422877   11950 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 15:02:43.422937   11950 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-179301362/tls.crt: no such file or directory"  
E0801 15:02:43.422957   11950 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 15:02:43.422978   11950 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-179301362/tls.crt: no such file or directory"  
I0801 15:02:43.422986   11950 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0801 15:02:43.423041   11950 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0801 15:02:43.425875   11950 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"



Summarizing 1 Failure:

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

Ran 5 of 5 Specs in 30.786 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (30.79s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	30.870s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.01s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0801 15:02:16.893831   12093 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.01s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
•I0801 15:02:29.793231   12093 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0801 15:02:29.796446   12093 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0801 15:02:29.862016   12093 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


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

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



Summarizing 1 Failure:

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

Ran 14 of 14 Specs in 8.106 seconds
FAIL! -- 13 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestPatch (8.11s)
=== 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	8.146s
?   	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.081s
... 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