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 03:00
Elapsed5m23s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I0801 03:02:59.213940    8478 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0801 03:02:59.214449    8478 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0801 03:02:59.215456    8478 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0801 03:02:59.215640    8478 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=40167
I0801 03:02:59.215815    8478 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0801 03:02:59.776784    8478 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 03:02:59.792197    8478 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 03:02:59.792250    8478 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-051852775/tls.crt: no such file or directory"  
E0801 03:02:59.792274    8478 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 03:02:59.792297    8478 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-051852775/tls.crt: no such file or directory"  
I0801 03:02:59.792310    8478 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.879 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.88s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	46.706s
=== 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 1409 lines ...
I0801 03:02:45.186084   10460 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
I0801 03:02:45.186600   10460 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"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_is_marked_ready_on_cluster
I0801 03:02:45.188279   10460 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"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_infrastructure_has_the_paused_annotation
2022/08/01 03:02:45 http: TLS handshake error from 127.0.0.1:46524: EOF
I0801 03:02:45.190119   10460 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"
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig/cluster_not_provisioned,_apiEndpoint_is_not_set
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig/kubeconfig_secret_found
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig/kubeconfig_secret_not_found,_should_requeue
I0801 03:02:45.192828   10460 cluster_controller_phases.go:270]  "msg"="could not find secret for cluster, requeuing" "cluster"="test-cluster" "namespace"="" "secret"="ca"
... skipping 94 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 03:02:45.218027   10460 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 03:02:45.219809   10460 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 03:02:45.220114   10460 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 03:02:45.220566   10460 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 03:02:45.471999   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0801 03:02:45.474344   10460 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0801 03:02:45.481174   10460 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-fbr78" "namespace"="test-machine-watches-wnqzr" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0801 03:02:45.481337   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0801 03:02:45.590224   10460 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-fbr78" "namespace"="test-machine-watches-wnqzr" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0801 03:02:45.590320   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0801 03:02:45.690854   10460 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-fbr78" "namespace"="test-machine-watches-wnqzr" "noderef"="node-1"
E0801 03:02:45.700527   10460 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0801 03:02:45.700577   10460 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0801 03:02:45.757822   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-fbr78\" in namespace \"test-machine-watches-wnqzr\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-fbr78" "namespace"="test-machine-watches-wnqzr"
E0801 03:02:46.761502   10460 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-fbr78\" in namespace \"test-machine-watches-wnqzr\", requeuing: requeue in 1s"  
E0801 03:02:46.767924   10460 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-fbr78\" in namespace \"test-machine-watches-wnqzr\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-fbr78\" in namespace \"test-machine-watches-wnqzr\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-fbr78" "namespace"="test-machine-watches-wnqzr"
--- PASS: TestWatches (1.58s)
=== 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 03:02:47.084489   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-4zzsj" "namespace"="test-machine-watches-wnqzr" "count"=1
I0801 03:02:47.084562   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-4zzsj" "namespace"="test-machine-watches-wnqzr" "descendants"="Worker machines: machine-created-fbr78" "indirect descendants count"=0
I0801 03:02:47.100041   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-4zzsj" "namespace"="test-machine-watches-wnqzr" "count"=1
I0801 03:02:47.100097   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-4zzsj" "namespace"="test-machine-watches-wnqzr" "descendants"="Worker machines: machine-created-fbr78" "indirect descendants count"=0
I0801 03:02:47.768557   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4zzsj" "machine"="machine-created-fbr78" "namespace"="test-machine-watches-wnqzr" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"ebb9e363-decb-4a37-b388-7e55d762a5fb","apiVersion":"v1"}
E0801 03:02:47.826901   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-fbr78\" not found" "controller"="machine" "name"="machine-created-fbr78" "namespace"="test-machine-watches-wnqzr"
E0801 03:02:48.885469   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-h8c9n\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-25w85\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-25w85: secrets \"machine-reconcile-25w85-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-h8c9n" "namespace"="default"
I0801 03:02:49.886025   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-25w85" "machine"="machine-created-h8c9n" "namespace"="default" "cause"="noderef is nil" "node"=null
I0801 03:02:49.923827   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-25w85" "machine"="machine-created-h8c9n" "namespace"="default" "cause"="noderef is nil" "node"=null
I0801 03:02:49.950936   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-25w85" "machine"="machine-created-h8c9n" "namespace"="default" "cause"="noderef is nil" "node"=null
E0801 03:02:49.983519   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-h8c9n\" not found" "controller"="machine" "name"="machine-created-h8c9n" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.20s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.20s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.01s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0801 03:02:50.025734   10460 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0801 03:02:50.032760   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-25w85\" not found" "controller"="cluster" "name"="machine-reconcile-25w85" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0801 03:02:50.037101   10460 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0801 03:02:50.042730   10460 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.02s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.01s)
... skipping 111 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_up (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0801 03:02:50.308450   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7dtqm" "namespace"="test-mhc-bk82t" 
I0801 03:02:50.324138   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0801 03:02:50.325544   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-tw9tt\" not found"  "cluster"="test-mhc-bk82t/test-cluster-tw9tt"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0801 03:02:50.362176   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-7dtqm\" not found" "controller"="machinehealthcheck" "name"="test-mhc-7dtqm" "namespace"="test-mhc-bk82t"
=== 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 03:02:51.362499   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7dtqm" "namespace"="test-mhc-bk82t" 
I0801 03:02:51.362627   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jfvnt" "namespace"="test-mhc-zsr9p" 
I0801 03:02:51.362660   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pm5ds" "namespace"="test-mhc-msb9q" 
I0801 03:02:51.362690   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-65mc5" "namespace"="test-mhc-mmqrc" 
I0801 03:02:51.386630   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 03:02:51.410407   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-65mc5" "namespace"="test-mhc-mmqrc" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0801 03:02:51.456706   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-65mc5" "namespace"="test-mhc-mmqrc" 
E0801 03:02:51.463917   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mmqrc/test-cluster-ddxqn"
E0801 03:02:51.465897   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-ddxqn\" not found" "controller"="cluster" "name"="test-cluster-ddxqn" "namespace"="test-mhc-mmqrc"
I0801 03:02:51.473964   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5bsk7" "namespace"="test-mhc-x4tj6" 
I0801 03:02:51.492498   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 03:02:51.617401   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5bsk7" "namespace"="test-mhc-x4tj6" 
E0801 03:02:51.679626   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-x4tj6/test-cluster-f2ztj"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0801 03:02:51.683740   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5bsk7" "namespace"="test-mhc-x4tj6" 
I0801 03:02:51.702595   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
inframachine created: test-mhc-machine-infra-pnkcp
I0801 03:02:51.715976   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-tx5vj
I0801 03:02:51.741377   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.748459   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.748784   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:51.764183   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.764477   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:51.769427   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.769763   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:51.782067   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.782393   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:51.786385   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.786729   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:51.811651   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.811982   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:51.817622   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.818004   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
node created: test-mhc-node-pm4wb
E0801 03:02:51.828711   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pm4wb, got []"  "node"="test-mhc-node-pm4wb"
E0801 03:02:51.828908   10460 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-pm4wb"
I0801 03:02:51.841902   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.842279   10460 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm" "noderef"="test-mhc-node-pm4wb"
inframachine created: test-mhc-machine-infra-lhcpl
machine created: test-mhc-machine-vk6pl
I0801 03:02:51.863952   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:51.885677   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
... skipping 45 lines ...
I0801 03:02:52.004799   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.006435   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.007651   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.008703   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.010955   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.012265   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.013144   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-vk6pl/"
I0801 03:02:52.022140   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.022530   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-vk6pl/"
I0801 03:02:52.039000   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.039493   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-vk6pl/"
I0801 03:02:52.051934   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.055390   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-vk6pl/"
E0801 03:02:52.079442   10460 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-69flw"
node created: test-mhc-node-69flw
E0801 03:02:52.079936   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-69flw, got []"  "node"="test-mhc-node-69flw"
I0801 03:02:52.080069   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.081585   10460 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-f5zrm/test-mhc-xs8w5/test-mhc-machine-vk6pl/"
I0801 03:02:52.098419   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.099371   10460 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm" "noderef"="test-mhc-node-69flw"
I0801 03:02:52.135981   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.154301   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
Cleaning up nodes, machines and infra machines.
I0801 03:02:52.164824   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.165316   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:52.190940   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:52.191485   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-f5zrm/test-mhc-xs8w5/test-mhc-machine-tx5vj/"
I0801 03:02:52.191969   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-f5zrm/test-mhc-xs8w5/test-mhc-machine-vk6pl/"
E0801 03:02:52.204761   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-f5zrm/test-cluster-ndkz8"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0801 03:02:52.215231   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-xs8w5\" not found" "controller"="machinehealthcheck" "name"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm"
inframachine created: test-mhc-machine-infra-5xgsm
E0801 03:02:52.351907   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
machine created: test-mhc-machine-vprs4
E0801 03:02:52.481107   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-wnqzr/machine-reconcile-4zzsj"
I0801 03:02:53.215508   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xs8w5" "namespace"="test-mhc-f5zrm" 
I0801 03:02:53.215605   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.229702   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 03:02:53.260695   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.261790   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.263610   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 30 lines ...
I0801 03:02:53.338150   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.340048   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.346228   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.348098   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.350016   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.351813   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:02:53.352545   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:02:53.353708   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.355437   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.357243   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.358975   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.360701   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:53.362376   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 435 lines ...
I0801 03:02:54.343140   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.344962   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.346657   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.348334   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.350017   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.351660   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:02:54.352878   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:02:54.353319   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.354987   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.356639   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.358304   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.360025   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:54.362238   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 492 lines ...
I0801 03:02:55.367157   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.368903   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.370658   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.371238   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.372335   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.373990   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:02:55.386788   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:02:55.387059   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.387500   10460 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-92gqx/test-mhc-nvnzb/test-mhc-machine-vprs4/"
I0801 03:02:55.416886   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.417195   10460 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-92gqx/test-mhc-nvnzb/test-mhc-machine-vprs4/"
node created: test-mhc-node-s5s4s
E0801 03:02:55.472948   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-s5s4s, got []"  "node"="test-mhc-node-s5s4s"
I0801 03:02:55.490198   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
inframachine created: test-mhc-machine-infra-zcxcs
I0801 03:02:55.505731   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:55.509980   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
machine created: test-mhc-machine-l2npg
I0801 03:02:55.520185   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 328 lines ...
I0801 03:02:56.373735   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.375904   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.378278   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.380690   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.382909   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.385067   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:02:56.387107   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:02:56.387207   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.389245   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.391360   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.393390   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.395475   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:56.397500   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 408 lines ...
I0801 03:02:57.433154   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.434946   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.445613   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.447040   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.448937   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.456996   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:02:57.458973   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:02:57.466378   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.467799   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.469040   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.484647   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.486117   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:57.487275   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 305 lines ...
I0801 03:02:58.467962   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.470302   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.473194   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.474956   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.476126   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.478851   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:02:58.480753   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:02:58.480828   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.481180   10460 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-92gqx/test-mhc-nvnzb/test-mhc-machine-l2npg/"
I0801 03:02:58.491806   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.492256   10460 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-92gqx/test-mhc-nvnzb/test-mhc-machine-l2npg/"
node created: test-mhc-node-f55wz
E0801 03:02:58.529851   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-f55wz, got []"  "node"="test-mhc-node-f55wz"
I0801 03:02:58.539198   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
inframachine created: test-mhc-machine-infra-7fdhr
machine created: test-mhc-machine-fprtm
I0801 03:02:58.555284   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.564069   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:58.565639   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 288 lines ...
I0801 03:02:59.478774   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.481293   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.484124   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.486772   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.489260   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.490783   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:02:59.491010   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:02:59.492153   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.509808   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.511334   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.512656   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.515207   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:02:59.517648   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 286 lines ...
I0801 03:03:00.510921   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.512401   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.513930   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.515707   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.517258   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.520103   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
E0801 03:03:00.524497   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:03:00.529052   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.531012   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.532852   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.534521   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.536034   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:00.537555   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
... skipping 269 lines ...
I0801 03:03:01.510170   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.512932   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.524509   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.529661   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.533662   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.540464   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.541476   10460 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-92gqx/test-mhc-nvnzb/test-mhc-machine-fprtm/"
E0801 03:03:01.545511   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:03:01.555717   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.556435   10460 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-92gqx/test-mhc-nvnzb/test-mhc-machine-fprtm/"
node created: test-mhc-node-ffwtf
E0801 03:03:01.588537   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ffwtf, got []"  "node"="test-mhc-node-ffwtf"
I0801 03:03:01.598819   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
Cleaning up nodes, machines and infra machines.
I0801 03:03:01.599468   10460 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-92gqx/test-mhc-nvnzb/test-mhc-machine-fprtm/test-mhc-node-ffwtf"
Cleaning up nodes, machines and infra machines.
I0801 03:03:01.620926   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.622080   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-92gqx/test-mhc-nvnzb/test-mhc-machine-fprtm/"
I0801 03:03:01.636479   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.637039   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-92gqx/test-mhc-nvnzb/test-mhc-machine-fprtm/"
I0801 03:03:01.637430   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-92gqx/test-mhc-nvnzb/test-mhc-machine-vprs4/"
I0801 03:03:01.669762   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:01.670471   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-92gqx/test-mhc-nvnzb/test-mhc-machine-fprtm/"
I0801 03:03:01.670838   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-92gqx/test-mhc-nvnzb/test-mhc-machine-vprs4/"
I0801 03:03:01.671335   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-92gqx/test-mhc-nvnzb/test-mhc-machine-l2npg/"
I0801 03:03:01.697791   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4hxhb" "namespace"="test-mhc-92gqx" "count"=2
I0801 03:03:01.697952   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4hxhb" "namespace"="test-mhc-92gqx" "descendants"="Worker machines: test-mhc-machine-vprs4,test-mhc-machine-l2npg,test-mhc-machine-fprtm" "indirect descendants count"=1
I0801 03:03:01.705010   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4hxhb" "namespace"="test-mhc-92gqx" "count"=2
I0801 03:03:01.705335   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4hxhb" "namespace"="test-mhc-92gqx" "descendants"="Worker machines: test-mhc-machine-fprtm,test-mhc-machine-vprs4,test-mhc-machine-l2npg" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
inframachine created: test-mhc-machine-infra-wh679
machine created: test-mhc-machine-5hccw
E0801 03:03:01.885663   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-nvnzb\" not found" "controller"="machinehealthcheck" "name"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx"
I0801 03:03:02.546077   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4hxhb" "machine"="test-mhc-machine-l2npg" "namespace"="test-mhc-92gqx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-f55wz"}
E0801 03:03:02.591083   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l2npg\" not found" "controller"="machine" "name"="test-mhc-machine-l2npg" "namespace"="test-mhc-92gqx"
I0801 03:03:02.901434   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:02.916607   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 03:03:03.051947   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnzb" "namespace"="test-mhc-92gqx" 
I0801 03:03:03.052010   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:03.058517   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:03.079479   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:03.120463   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:03.201418   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:03.362401   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:03.591581   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:03:03.683645   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:04.326897   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:04.592121   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4hxhb" "machine"="test-mhc-machine-fprtm" "namespace"="test-mhc-92gqx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ffwtf"}
E0801 03:03:04.656356   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fprtm\" not found" "controller"="machine" "name"="test-mhc-machine-fprtm" "namespace"="test-mhc-92gqx"
I0801 03:03:05.608188   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:05.656840   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:03:06.657335   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4hxhb" "machine"="test-mhc-machine-vprs4" "namespace"="test-mhc-92gqx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-s5s4s"}
I0801 03:03:06.705068   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4hxhb" "namespace"="test-mhc-92gqx" "count"=1
I0801 03:03:06.705150   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4hxhb" "namespace"="test-mhc-92gqx" "descendants"="Worker machines: test-mhc-machine-vprs4" "indirect descendants count"=0
E0801 03:03:06.710469   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vprs4\" not found" "controller"="machine" "name"="test-mhc-machine-vprs4" "namespace"="test-mhc-92gqx"
I0801 03:03:07.719222   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:07.725808   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:03:07.726109   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:07.750649   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:07.794984   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t5ncj, got []"  "node"="test-mhc-node-t5ncj"
node created: test-mhc-node-t5ncj
E0801 03:03:07.795114   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t5ncj, got []"  "node"="test-mhc-node-t5ncj"
I0801 03:03:07.802307   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
inframachine created: test-mhc-machine-infra-gp9j7
I0801 03:03:07.822913   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:07.824925   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
machine created: test-mhc-machine-m5psg
I0801 03:03:07.839925   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:07.844883   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:07.847178   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:07.867668   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:07.949521   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:08.117440   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:08.438687   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:08.726189   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:03:09.080102   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.740684   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.741837   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.748305   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.759803   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.763974   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.771663   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.784921   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:09.785349   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:03:09.810172   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
node created: test-mhc-node-xltlw
E0801 03:03:09.842845   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xltlw, got []"  "node"="test-mhc-node-xltlw"
E0801 03:03:09.842845   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xltlw, got []"  "node"="test-mhc-node-xltlw"
I0801 03:03:09.850036   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
inframachine created: test-mhc-machine-infra-tp4ll
I0801 03:03:09.861457   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
machine created: test-mhc-machine-zgcr5
I0801 03:03:09.867174   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.877464   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:09.889877   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:10.361263   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:10.785755   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
E0801 03:03:11.718845   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-92gqx/test-cluster-4hxhb"
I0801 03:03:11.797493   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:11.819815   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:11.828246   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:11.841567   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:11.850354   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:11.860458   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
E0801 03:03:11.864252   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:03:11.866145   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
node created: test-mhc-node-xs446
E0801 03:03:11.895569   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xs446, got []"  "node"="test-mhc-node-xs446"
I0801 03:03:11.915346   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
Cleaning up nodes, machines and infra machines.
I0801 03:03:11.938161   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:11.959320   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
Cleaning up nodes, machines and infra machines.
I0801 03:03:12.002649   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-kdzm9" "namespace"="test-mhc-g7chb" "count"=2
... skipping 4 lines ...
inframachine created: test-mhc-machine-infra-qbwc4
machine created: test-mhc-machine-nsrq2
I0801 03:03:12.150494   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:12.165062   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 03:03:12.284587   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7b76c" "namespace"="test-mhc-g7chb" 
I0801 03:03:12.284652   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
E0801 03:03:12.864888   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:03:13.865541   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kdzm9" "machine"="test-mhc-machine-5hccw" "namespace"="test-mhc-g7chb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-t5ncj"}
E0801 03:03:13.917321   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5hccw\" not found" "controller"="machine" "name"="test-mhc-machine-5hccw" "namespace"="test-mhc-g7chb"
I0801 03:03:14.918218   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kdzm9" "machine"="test-mhc-machine-m5psg" "namespace"="test-mhc-g7chb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xltlw"}
E0801 03:03:14.975489   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-m5psg\" not found" "controller"="machine" "name"="test-mhc-machine-m5psg" "namespace"="test-mhc-g7chb"
I0801 03:03:15.975983   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-kdzm9" "machine"="test-mhc-machine-zgcr5" "namespace"="test-mhc-g7chb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xs446"}
E0801 03:03:16.020837   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zgcr5\" not found" "controller"="machine" "name"="test-mhc-machine-zgcr5" "namespace"="test-mhc-g7chb"
E0801 03:03:17.022840   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-g7chb/test-cluster-kdzm9"
I0801 03:03:17.030277   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:17.035831   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
E0801 03:03:17.036870   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
node created: test-mhc-node-k4q8f
E0801 03:03:17.083739   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-k4q8f, got []"  "node"="test-mhc-node-k4q8f"
I0801 03:03:17.090384   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
inframachine created: test-mhc-machine-infra-2lptz
machine created: test-mhc-machine-cg7vq
I0801 03:03:17.108849   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:17.114453   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
E0801 03:03:18.041190   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:03:19.058406   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.073884   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.091971   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.098228   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.113796   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.116768   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
node created: test-mhc-node-jxf4z
E0801 03:03:19.124510   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jxf4z, got []"  "node"="test-mhc-node-jxf4z"
I0801 03:03:19.128791   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.134528   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
inframachine created: test-mhc-machine-infra-l6xnf
I0801 03:03:19.147484   10460 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-cg7vq" "namespace"="test-mhc-84l84" "noderef"="test-mhc-node-jxf4z"
machine created: test-mhc-machine-kcb2m
I0801 03:03:19.170469   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
... skipping 8 lines ...
I0801 03:03:19.258542   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.265104   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.274026   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
Cleaning up nodes, machines and infra machines.
I0801 03:03:19.279330   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-49llc" "machine"="test-mhc-machine-kcb2m" "namespace"="test-mhc-84l84" "cause"="noderef is nil" "node"=null
I0801 03:03:19.279828   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.280332   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-84l84/test-mhc-rsmhh/test-mhc-machine-nsrq2/"
I0801 03:03:19.327151   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.327869   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-84l84/test-mhc-rsmhh/test-mhc-machine-nsrq2/"
I0801 03:03:19.328426   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-84l84/test-mhc-rsmhh/test-mhc-machine-cg7vq/"
I0801 03:03:19.354111   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.356354   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-84l84/test-mhc-rsmhh/test-mhc-machine-nsrq2/"
I0801 03:03:19.357475   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-84l84/test-mhc-rsmhh/test-mhc-machine-cg7vq/"
E0801 03:03:19.365205   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kcb2m\" not found" "controller"="machine" "name"="test-mhc-machine-kcb2m" "namespace"="test-mhc-84l84"
I0801 03:03:19.366562   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-49llc" "namespace"="test-mhc-84l84" "count"=3
I0801 03:03:19.366656   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-49llc" "namespace"="test-mhc-84l84" "descendants"="Worker machines: test-mhc-machine-nsrq2,test-mhc-machine-cg7vq,test-mhc-machine-kcb2m" "indirect descendants count"=0
I0801 03:03:19.372060   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:19.372608   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-84l84/test-mhc-rsmhh/test-mhc-machine-cg7vq/"
I0801 03:03:19.373083   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-84l84/test-mhc-rsmhh/test-mhc-machine-nsrq2/"
I0801 03:03:19.375434   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-49llc" "namespace"="test-mhc-84l84" "count"=2
I0801 03:03:19.375497   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-49llc" "namespace"="test-mhc-84l84" "descendants"="Worker machines: test-mhc-machine-nsrq2,test-mhc-machine-cg7vq" "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
E0801 03:03:19.386945   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-rsmhh\" not found" "controller"="machinehealthcheck" "name"="test-mhc-rsmhh" "namespace"="test-mhc-84l84"
inframachine created: test-mhc-machine-infra-2cbjc
machine created: test-mhc-machine-nm7zk
I0801 03:03:20.365924   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-49llc" "machine"="test-mhc-machine-nsrq2" "namespace"="test-mhc-84l84" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-k4q8f"}
I0801 03:03:20.387243   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rsmhh" "namespace"="test-mhc-84l84" 
I0801 03:03:20.387355   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:20.403149   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0801 03:03:20.425260   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nsrq2\" not found" "controller"="machine" "name"="test-mhc-machine-nsrq2" "namespace"="test-mhc-84l84"
I0801 03:03:20.425561   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:20.426714   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:20.428509   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:20.430288   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:20.432096   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:20.433904   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
... skipping 478 lines ...
I0801 03:03:21.464205   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.465969   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.467741   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.469514   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.472311   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.474761   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
E0801 03:03:21.475625   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cg7vq\" not found" "controller"="machine" "name"="test-mhc-machine-cg7vq" "namespace"="test-mhc-84l84"
I0801 03:03:21.477231   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.479035   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.480860   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.482624   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.484272   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:21.486182   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
... skipping 438 lines ...
I0801 03:03:22.483945   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.488357   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.490595   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.492375   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.494037   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.495445   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.495679   10460 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-5qxcm/test-mhc-7frt5/test-mhc-machine-nm7zk/"
E0801 03:03:22.496893   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:03:22.515318   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.515625   10460 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-5qxcm/test-mhc-7frt5/test-mhc-machine-nm7zk/"
E0801 03:03:22.531580   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-95trn, got []"  "node"="test-mhc-node-95trn"
node created: test-mhc-node-95trn
E0801 03:03:22.532765   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-95trn, got []"  "node"="test-mhc-node-95trn"
I0801 03:03:22.550169   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.565037   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.574316   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.574705   10460 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-5qxcm/test-mhc-7frt5/test-mhc-machine-nm7zk/test-mhc-node-95trn"
I0801 03:03:22.588717   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.589141   10460 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-5qxcm/test-mhc-7frt5/test-mhc-machine-nm7zk/test-mhc-node-95trn"
Cleaning up nodes, machines and infra machines.
I0801 03:03:22.599559   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.599884   10460 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-5qxcm/test-mhc-7frt5/test-mhc-machine-nm7zk/"
I0801 03:03:22.612691   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jvcln" "namespace"="test-mhc-5qxcm" "descendants"="Worker machines: test-mhc-machine-nm7zk" "indirect descendants count"=1
I0801 03:03:22.616226   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jvcln" "namespace"="test-mhc-5qxcm" "descendants"="Worker machines: test-mhc-machine-nm7zk" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0801 03:03:22.742136   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" "creating"=1 "need"=1
I0801 03:03:22.742224   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
I0801 03:03:22.743988   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7frt5" "namespace"="test-mhc-5qxcm" 
I0801 03:03:22.754449   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-6cxxt-pfzxj\"" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
I0801 03:03:22.809022   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:22.832024   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 03:03:22.861083   10460 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
I0801 03:03:22.863705   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:22.864473   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
E0801 03:03:23.497381   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:03:23.863963   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
E0801 03:03:24.396905   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-84l84/test-cluster-49llc"
I0801 03:03:24.497872   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jvcln" "machine"="test-mhc-machine-nm7zk" "namespace"="test-mhc-5qxcm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-95trn"}
E0801 03:03:24.558724   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nm7zk\" not found" "controller"="machine" "name"="test-mhc-machine-nm7zk" "namespace"="test-mhc-5qxcm"
I0801 03:03:24.865418   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:25.567227   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:25.567890   10460 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
I0801 03:03:25.580110   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:25.580398   10460 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
I0801 03:03:25.593527   10460 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
... skipping 7 lines ...
I0801 03:03:25.636544   10460 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:25.636613   10460 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:25.866352   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:26.621961   10460 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:26.622007   10460 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.000553   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.001008   10460 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-4vfch/test-mhc-4rmzw/mhc-ms-6cxxt-pfzxj/"
I0801 03:03:27.007806   10460 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.013724   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.014075   10460 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-4vfch/test-mhc-4rmzw/mhc-ms-6cxxt-pfzxj/"
I0801 03:03:27.017912   10460 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.017958   10460 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.031795   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.032035   10460 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.032199   10460 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-4vfch/test-mhc-4rmzw/mhc-ms-6cxxt-pfzxj/"
I0801 03:03:27.051628   10460 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.051677   10460 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.066438   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-f72qr" "namespace"="test-mhc-4vfch" "count"=1
I0801 03:03:27.066492   10460 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-f72qr" "namespace"="test-mhc-4vfch" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-6cxxt"
I0801 03:03:27.066976   10460 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" "machine"="mhc-ms-6cxxt-pfzxj"
I0801 03:03:27.072259   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.072662   10460 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-4vfch/test-mhc-4rmzw/mhc-ms-6cxxt-pfzxj/"
I0801 03:03:27.072716   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-f72qr" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" "cause"="cluster is being deleted" "node"=null
I0801 03:03:27.081200   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-f72qr" "namespace"="test-mhc-4vfch" "descendants"="Machine sets: mhc-ms-6cxxt;Worker machines: mhc-ms-6cxxt-pfzxj" "indirect descendants count"=1
I0801 03:03:27.084996   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.085495   10460 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-4vfch/test-mhc-4rmzw/mhc-ms-6cxxt-pfzxj/"
I0801 03:03:27.086797   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-f72qr" "namespace"="test-mhc-4vfch" "descendants"="Worker machines: mhc-ms-6cxxt-pfzxj" "indirect descendants count"=1
E0801 03:03:27.092820   10460 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-6cxxt\" not found" "machineset"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch" 
E0801 03:03:27.092896   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-6cxxt\" not found" "controller"="machineset" "name"="mhc-ms-6cxxt" "namespace"="test-mhc-4vfch"
=== 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
I0801 03:03:27.098705   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rmzw" "namespace"="test-mhc-4vfch" 
I0801 03:03:27.158772   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
inframachine created: test-mhc-machine-infra-ndjwt
machine created: test-mhc-machine-86k8s
I0801 03:03:27.183609   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0801 03:03:27.273573   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-f72qr" "machine"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch" "cause"="cluster is being deleted" "node"=null
node created: test-mhc-node-bsqg5
E0801 03:03:27.285917   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bsqg5, got []"  "node"="test-mhc-node-bsqg5"
E0801 03:03:27.285931   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bsqg5, got []"  "node"="test-mhc-node-bsqg5"
E0801 03:03:27.285962   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bsqg5, got []"  "node"="test-mhc-node-bsqg5"
E0801 03:03:27.311670   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-6cxxt-pfzxj\" not found" "controller"="machine" "name"="mhc-ms-6cxxt-pfzxj" "namespace"="test-mhc-4vfch"
I0801 03:03:27.349895   10460 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-86k8s" "target"="test-mhc-ckvp7/test-mhc-8z5p4/test-mhc-machine-86k8s/"
I0801 03:03:27.398402   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
I0801 03:03:27.423782   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
I0801 03:03:27.428194   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
I0801 03:03:27.432035   10460 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-86k8s" "target"="test-mhc-ckvp7/test-mhc-8z5p4/test-mhc-machine-86k8s/test-mhc-node-bsqg5"
I0801 03:03:27.461006   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
Cleaning up nodes, machines and infra machines.
I0801 03:03:27.479303   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
I0801 03:03:27.482959   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
I0801 03:03:27.487189   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
I0801 03:03:27.494987   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zqlj6" "namespace"="test-mhc-ckvp7" "descendants"="Worker machines: test-mhc-machine-86k8s" "indirect descendants count"=1
I0801 03:03:27.499116   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zqlj6" "namespace"="test-mhc-ckvp7" "descendants"="Worker machines: test-mhc-machine-86k8s" "indirect descendants count"=1
I0801 03:03:27.501401   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8z5p4" "namespace"="test-mhc-ckvp7" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0801 03:03:27.528430   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
inframachine created: test-mhc-machine-infra-nxqmt
I0801 03:03:27.557961   10460 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-62mrb
E0801 03:03:27.660677   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5qxcm/test-cluster-jvcln"
I0801 03:03:27.685931   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:27.687025   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:27.688963   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:27.690876   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:27.692974   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:27.695550   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
... skipping 307 lines ...
I0801 03:03:28.343414   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.345202   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.346990   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.348866   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.350606   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.352336   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
E0801 03:03:28.352613   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-86k8s\" not found" "controller"="machine" "name"="test-mhc-machine-86k8s" "namespace"="test-mhc-ckvp7"
I0801 03:03:28.354063   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.355827   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.357608   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.359440   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.361215   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:28.363081   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
... skipping 507 lines ...
I0801 03:03:29.358535   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.360451   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.361837   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.362638   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.363770   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.366016   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
E0801 03:03:29.366354   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
I0801 03:03:29.369377   10460 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-62mrb" "target"="test-mhc-jwj52/test-mhc-c7zq2/test-mhc-machine-62mrb/"
node created: test-mhc-node-hnndk
E0801 03:03:29.379477   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hnndk, got []"  "node"="test-mhc-node-hnndk"
E0801 03:03:29.379477   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hnndk, got []"  "node"="test-mhc-node-hnndk"
E0801 03:03:29.379808   10460 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hnndk, got []"  "node"="test-mhc-node-hnndk"
I0801 03:03:29.385030   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.387750   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.412106   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.420595   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.436457   10460 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-62mrb" "target"="test-mhc-jwj52/test-mhc-c7zq2/test-mhc-machine-62mrb/test-mhc-node-hnndk"
I0801 03:03:29.452855   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.455345   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.465065   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.484440   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
Cleaning up nodes, machines and infra machines.
I0801 03:03:29.489957   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:29.495368   10460 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-62mrb" "target"="test-mhc-jwj52/test-mhc-c7zq2/test-mhc-machine-62mrb/"
I0801 03:03:29.521338   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-s7wqc" "namespace"="test-mhc-jwj52" "descendants"="Worker machines: test-mhc-machine-62mrb" "indirect descendants count"=1
I0801 03:03:29.530484   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-s7wqc" "namespace"="test-mhc-jwj52" "descendants"="Worker machines: test-mhc-machine-62mrb" "indirect descendants count"=1
E0801 03:03:29.535485   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-c7zq2\" not found" "controller"="machinehealthcheck" "name"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52"
--- PASS: TestMachineHealthCheck_Reconcile (39.37s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.18s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (0.94s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.23s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.41s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.04s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0801 03:03:29.542596   10460 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 03:03:29.544771   10460 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 03:03:29.547250   10460 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0801 03:03:29.547603   10460 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 03:03:29.548195   10460 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 03:03:29.551727   10460 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0801 03:03:29.552341   10460 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0801 03:03:29.554264   10460 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0801 03:03:29.565417   10460 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 03:03:29.567352   10460 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1659322952
Will run 16 of 16 specs

•E0801 03:03:29.692688   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-nm6jr\" not found" "controller"="cluster" "name"="test1-nm6jr" "namespace"="default"
E0801 03:03:30.366933   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
I0801 03:03:30.535840   10460 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-c7zq2" "namespace"="test-mhc-jwj52" 
I0801 03:03:30.808616   10460 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-s26pz" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0801 03:03:30.923289   10460 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-s26pz" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0801 03:03:30.928198   10460 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-s26pz" "namespace"="default"
I0801 03:03:31.367538   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-s7wqc" "machine"="test-mhc-machine-62mrb" "namespace"="test-mhc-jwj52" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hnndk"}
E0801 03:03:31.416098   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-62mrb\" not found" "controller"="machine" "name"="test-mhc-machine-62mrb" "namespace"="test-mhc-jwj52"
E0801 03:03:31.942211   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"
•E0801 03:03:32.955870   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-nbmln\" not found" "controller"="cluster" "name"="test3-nbmln" "namespace"="default"
E0801 03:03:33.956671   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"
E0801 03:03:34.973813   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4vfch/test-cluster-f72qr"
E0801 03:03:34.982833   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-ckvp7/test-cluster-zqlj6"
E0801 03:03:34.983358   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"
•E0801 03:03:35.995493   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jwj52/test-cluster-s7wqc"
E0801 03:03:35.997848   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bm7jt: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bm7jt" "namespace"="default"
E0801 03:03:36.998524   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"
E0801 03:03:38.007731   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bm7jt: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bm7jt" "namespace"="default"
•E0801 03:03:39.008493   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"
E0801 03:03:39.606782   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-tx5vj\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-tx5vj" "namespace"="test-mhc-f5zrm"
E0801 03:03:40.009338   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bm7jt: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bm7jt" "namespace"="default"
E0801 03:03:40.607275   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ndkz8\" for machine \"test-mhc-machine-vk6pl\" in namespace \"test-mhc-f5zrm\": Cluster.cluster.x-k8s.io \"test-cluster-ndkz8\" not found" "controller"="machine" "name"="test-mhc-machine-vk6pl" "namespace"="test-mhc-f5zrm"
E0801 03:03:41.018102   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"
I0801 03:03:41.631989   10460 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-chdnt" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0801 03:03:41.642033   10460 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-chdnt" "namespace"="default" 
E0801 03:03:41.659972   10460 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-chdnt" "namespace"="default"
E0801 03:03:42.018818   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bm7jt: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bm7jt" "namespace"="default"
I0801 03:03:42.674332   10460 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-chdnt" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0801 03:03:42.674530   10460 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-chdnt" "namespace"="default" "noderef"="id-node-1"
E0801 03:03:42.685787   10460 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-chdnt" "namespace"="default"
E0801 03:03:43.023383   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"

------------------------------
• [SLOW TEST:5.038 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 12 lines ...
I0801 03:03:43.323810   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0801 03:03:43.323904   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" 
I0801 03:03:43.337608   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-s648t-6657c7fddb-k2ttn\"" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" 
I0801 03:03:43.432147   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0801 03:03:43.432307   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" 
I0801 03:03:43.441407   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-s648t-cdfc6fd6c-lpzq9\"" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" 
E0801 03:03:43.654699   10460 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-s648t-cdfc6fd6c-lpzq9-5qgm5 for machine md-test/md-s648t-cdfc6fd6c-lpzq9: the cache is not started, can not read objects" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" 
I0801 03:03:43.682685   10460 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0801 03:03:43.682767   10460 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0801 03:03:43.686171   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-6r5f6" "machine"="test6-chdnt" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"2eff658f-a2df-4ec2-acbd-2969973f1a6b","apiVersion":"v1"}
I0801 03:03:43.686300   10460 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "machine"="md-s648t-6657c7fddb-n87c4"
E0801 03:03:43.704982   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-chdnt\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-chdnt" "namespace"="default"
I0801 03:03:43.798231   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0801 03:03:43.798283   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" 
I0801 03:03:43.806880   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-s648t-cdfc6fd6c-7ddw2\"" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" 
I0801 03:03:44.007625   10460 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0801 03:03:44.007663   10460 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0801 03:03:44.013323   10460 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "machine"="md-s648t-6657c7fddb-85l6l"
E0801 03:03:44.023963   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-bm7jt: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-bm7jt" "namespace"="default"
I0801 03:03:44.120983   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0801 03:03:44.121030   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" 
I0801 03:03:44.129392   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-s648t-cdfc6fd6c-nr9pp\"" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" 
I0801 03:03:44.357383   10460 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0801 03:03:44.357422   10460 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0801 03:03:44.361866   10460 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-s648t-6657c7fddb" "namespace"="md-test" "machine"="md-s648t-6657c7fddb-k2ttn"
I0801 03:03:44.607341   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0801 03:03:44.607385   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" 
I0801 03:03:44.619264   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-s648t-74d45c49c5-tszdg\"" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" 
I0801 03:03:44.741822   10460 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-6r5f6" "machine"="test6-chdnt" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"2eff658f-a2df-4ec2-acbd-2969973f1a6b","apiVersion":"v1"}
E0801 03:03:44.742737   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-chdnt\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-chdnt" "namespace"="default"
I0801 03:03:44.748990   10460 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0801 03:03:44.749032   10460 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0801 03:03:44.753221   10460 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "machine"="md-s648t-cdfc6fd6c-nr9pp"
I0801 03:03:44.862984   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0801 03:03:44.863038   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" 
I0801 03:03:44.873229   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-s648t-74d45c49c5-h4jpv\"" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" 
I0801 03:03:45.024518   10460 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-6r5f6" "namespace"="default" "count"=1
I0801 03:03:45.024588   10460 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-6r5f6" "namespace"="default" "descendants"="Control plane machines: test6-chdnt" "indirect descendants count"=0
E0801 03:03:45.038418   10460 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s26pz: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s26pz" "namespace"="default"
I0801 03:03:45.072232   10460 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0801 03:03:45.072268   10460 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0801 03:03:45.076999   10460 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-s648t-cdfc6fd6c" "namespace"="md-test" "machine"="md-s648t-cdfc6fd6c-7ddw2"
I0801 03:03:45.102050   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0801 03:03:45.102103   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" 
I0801 03:03:45.109907   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-s648t-74d45c49c5-mxt5n\"" "machineset"="md-s648t-74d45c49c5" "namespace"="md-test" 
... skipping 5 lines ...
I0801 03:03:45.299780   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-nf6jt-gzdvs\"" "machineset"="ms-nf6jt" "namespace"="ms-test" 
I0801 03:03:45.299855   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-nf6jt" "namespace"="ms-test" 
I0801 03:03:45.313799   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-nf6jt-4znxd\"" "machineset"="ms-nf6jt" "namespace"="ms-test" 
I0801 03:03:45.412316   10460 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-nf6jt" "namespace"="ms-test" "creating"=1 "need"=2
I0801 03:03:45.412356   10460 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-nf6jt" "namespace"="ms-test" 
I0801 03:03:45.425949   10460 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-nf6jt-sgtrq\"" "machineset"="ms-nf6jt" "namespace"="ms-test" 
E0801 03:03:45.576493   10460 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-nf6jt-sgtrq-2gctz for machine ms-test/ms-nf6jt-sgtrq: the cache is not started, can not read objects" "machineset"="ms-nf6jt" "namespace"="ms-test" 
E0801 03:03:45.694774   10460 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0801 03:03:45.697474   10460 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 03:03:45.698614   10460 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0801 03:03:45.698678   10460 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 03:03:45.699546   10460 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0801 03:03:45.699582   10460 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0801 03:03:45.700237   10460 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 03:03:45.708938   10460 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 03:03:45.710421   10460 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 03:03:45.711154   10460 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 03:03:45.711765   10460 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0801 03:03:45.711794   10460 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0801 03:03:45.712307   10460 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0801 03:03:45.713561   10460 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.144 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.14s)
PASS
Tearing down test suite
I0801 03:03:45.715058   10460 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0801 03:03:45.715105   10460 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0801 03:03:45.715173   10460 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0801 03:03:45.715183   10460 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0801 03:03:45.715206   10460 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0801 03:03:45.715221   10460 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0801 03:03:45.715235   10460 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0801 03:03:45.740848   10460 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:45601/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1253&timeout=10s&timeoutSeconds=393&watch=true: dial tcp 127.0.0.1:45601: connect: connection refused
E0801 03:03:45.741074   10460 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:45601/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1253&timeout=10s&timeoutSeconds=579&watch=true: dial tcp 127.0.0.1:45601: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	73.236s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0801 03:02:48.176672   10979 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0801 03:02:48.176699   10979 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0801 03:02:48.176876   10979 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0801 03:02:48.177786   10979 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0801 03:02:48.177971   10979 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=34709
I0801 03:02:48.178101   10979 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0801 03:02:50.300091   10979 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-lctf4/test-cluster"
•E0801 03:02:50.801483   10979 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-hppbf/test-cluster"
•E0801 03:02:51.380237   10979 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:34553/?timeout=50ms: dial tcp 127.0.0.1:34553: connect: connection refused"  "cluster"="cluster-cache-test-lsxxx/test-cluster"
•I0801 03:02:51.621515   10979 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 03:02:51.927186   10979 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0801 03:02:51.927241   10979 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0801 03:02:51.927305   10979 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0801 03:02:52.451100   10979 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0801 03:02:52.467767   10979 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0801 03:02:52.581466   10979 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0801 03:02:52.581527   10979 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•E0801 03:02:52.751239   10979 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 03:02:52.751291   10979 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-996087510/tls.crt: no such file or directory"  
I0801 03:02:52.751316   10979 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0801 03:02:52.751366   10979 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0801 03:02:52.779547   10979 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:33541/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:33541: connect: connection refused


Ran 5 of 5 Specs in 18.190 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (18.19s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	18.373s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 201 lines ...
=== RUN   TestClusterToKubeadmControlPlaneOtherControlPlane
I0801 03:02:58.014767   11582 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
--- PASS: TestClusterToKubeadmControlPlaneOtherControlPlane (0.00s)
=== RUN   TestReconcileUpdateObservedGeneration
I0801 03:02:58.015009   11582 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=37725
I0801 03:02:58.015386   11582 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
--- FAIL: TestReconcileUpdateObservedGeneration (11.02s)
    controller_test.go:230: 
        Timed out after 10.000s.
        Expected
            <int64>: 2
        to equal
            <int64>: 1
=== RUN   TestReconcileNoClusterOwnerRef
I0801 03:03:09.037833   11582 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 03:03:09.039156   11582 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 03:03:09.039806   11582 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0801 03:03:09.039967   11582 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 03:03:22.912499   11582 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 03:03:22.912699   11582 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: 1659322964
Will run 1 of 1 specs

E0801 03:03:22.946041   11582 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-1win8f\" not found" "kubeadmControlPlane"="kcp-foo-1win8f" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.029 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.03s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0801 03:03:22.947578   11582 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-q7yog3" "kubeadmControlPlane"="kcp-foo-q7yog3" "namespace"="test" 
I0801 03:03:24.422673   11582 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-q7yog3" "kubeadmControlPlane"="kcp-foo-q7yog3" "namespace"="test" "needRollout"=["kcp-foo-q7yog3-vsfdt"]
I0801 03:03:24.422836   11582 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-q7yog3" "kubeadmControlPlane"="kcp-foo-q7yog3" "namespace"="test" "failures"="[machine kcp-foo-q7yog3-wcnzq does not have APIServerPodHealthy condition, machine kcp-foo-q7yog3-wcnzq does not have ControllerManagerPodHealthy condition, machine kcp-foo-q7yog3-wcnzq does not have SchedulerPodHealthy condition, machine kcp-foo-q7yog3-wcnzq does not have EtcdPodHealthy condition, machine kcp-foo-q7yog3-wcnzq does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.48s)
FAIL
I0801 03:03:24.423812   11582 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	39.660s
I0801 03:02:55.483529   11538 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0801 03:02:55.484953   11538 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0801 03:02:55.485055   11538 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0801 03:02:55.485109   11538 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0801 03:02:55.485236   11538 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
I0801 03:02:55.485290   11538 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1659322963
Will run 7 of 7 specs

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

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0801 03:02:58.552063   11538 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 03:03:06.875116   11538 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 03:03:15.861121   11538 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 03:03:26.991390   11538 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 03:03:43.464595   11538 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 03:03:56.473183   11538 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 03:04:14.120592   11538 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 03:04:35.043910   11538 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 03:05:06.060452   11538 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 03:05:51.217661   11538 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 84 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
I0801 03:05:51.232410   11538 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0801 03:05:51.232540   11538 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0801 03:05:51.232679   11538 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-544110831/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	187.397s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
... skipping 287 lines ...
I0801 03:03:06.119286   11862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0801 03:03:06.119327   11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0801 03:03:06.120352   11862 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0801 03:03:06.220768   11862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0801 03:03:06.220852   11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0801 03:03:06.307031   11862 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-iqb9zg"} 
E0801 03:03:06.336679   11862 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•I0801 03:03:07.372283   11862 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-3mjbap"} 
•E0801 03:03:07.422270   11862 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0801 03:03:18.508207   11862 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"

------------------------------
• Failure [11.093 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0801 03:03:19.671718   11862 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0801 03:03:20.723930   11862 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset2\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset2" "namespace"="default"
E0801 03:03:21.738133   11862 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0801 03:03:21.746810   11862 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0801 03:03:21.746835   11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0801 03:03:21.746871   11862 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-986668179/tls.crt: no such file or directory"  
I0801 03:03:21.746874   11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0801 03:03:21.746890   11862 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 03:03:21.746909   11862 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-986668179/tls.crt: no such file or directory"  
I0801 03:03:21.746980   11862 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

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

Ran 5 of 5 Specs in 29.054 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (29.05s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	29.123s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0801 03:03:00.907359   12121 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 92 lines ...
•I0801 03:03:12.954748   12121 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0801 03:03:12.986770   12121 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0801 03:03:12.989379   12121 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0801 03:03:13.016717   12121 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0801 03:03:13.017814   12121 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}}}
I0801 03:03:13.075062   12121 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0801 03:03:13.078636   12121 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 03:03:13.078676   12121 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-406739853/tls.crt: no such file or directory"  
E0801 03:03:13.078697   12121 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0801 03:03:13.078716   12121 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-406739853/tls.crt: no such file or directory"  
I0801 03:03:13.078953   12121 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 12.207 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (12.21s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	12.485s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 204 lines ...
I0801 03:03:36.054612   15150 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0801 03:03:36.054705   15150 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=41243
••••••••••••••I0801 03:03:37.031292   15150 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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